2025-11-20 00:13:44.615565 | Job console starting... 2025-11-20 00:13:44.629185 | Updating repositories 2025-11-20 00:13:44.783709 | Preparing job workspace 2025-11-20 00:13:49.179758 | Running Ansible setup... 2025-11-20 00:13:54.085673 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-20 00:13:54.720793 | 2025-11-20 00:13:54.720922 | PLAY [localhost] 2025-11-20 00:13:54.737958 | 2025-11-20 00:13:54.738278 | TASK [Gathering Facts] 2025-11-20 00:13:55.788629 | localhost | ok 2025-11-20 00:13:55.809855 | 2025-11-20 00:13:55.810086 | TASK [Setup log path fact] 2025-11-20 00:13:55.829152 | localhost | ok 2025-11-20 00:13:55.842117 | 2025-11-20 00:13:55.842237 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-20 00:13:55.878535 | localhost | ok 2025-11-20 00:13:55.899485 | 2025-11-20 00:13:55.899846 | TASK [emit-job-header : Print job information] 2025-11-20 00:13:55.942103 | # Job Information 2025-11-20 00:13:55.942299 | Ansible Version: 2.15.12 2025-11-20 00:13:55.942345 | Job: ansible-test-sanity-docker-devel 2025-11-20 00:13:55.942935 | Pipeline: periodic 2025-11-20 00:13:55.942998 | Executor: ze01.softwarefactory-project.io 2025-11-20 00:13:55.943071 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-20 00:13:55.943111 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/bd8/ansible/bd8e6da99dad4242a3099f3ccf1e7b43/ 2025-11-20 00:13:55.943140 | Event ID: 4015b71040db4124b5e62c0aaaa553e0 2025-11-20 00:13:55.949277 | 2025-11-20 00:13:55.949415 | LOOP [emit-job-header : Print node information] 2025-11-20 00:13:56.071234 | localhost | ok: 2025-11-20 00:13:56.071453 | localhost | # Node Information 2025-11-20 00:13:56.071481 | localhost | Inventory Hostname: controller 2025-11-20 00:13:56.071501 | localhost | Hostname: np0005528748 2025-11-20 00:13:56.071520 | localhost | Username: zuul 2025-11-20 00:13:56.071545 | localhost | Distro: Fedora 37 2025-11-20 00:13:56.071566 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-11-20 00:13:56.071584 | localhost | Region: ca-ymq-1 2025-11-20 00:13:56.071602 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-20 00:13:56.071619 | localhost | Product Name: OpenStack Nova 2025-11-20 00:13:56.071637 | localhost | Interface IP: 162.253.55.204 2025-11-20 00:13:56.089312 | 2025-11-20 00:13:56.089450 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-20 00:13:56.513710 | localhost -> localhost | changed 2025-11-20 00:13:56.522497 | 2025-11-20 00:13:56.522628 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-20 00:13:57.475271 | localhost -> localhost | changed 2025-11-20 00:13:57.494934 | 2025-11-20 00:13:57.495307 | PLAY [all:!appliance*] 2025-11-20 00:13:57.512285 | 2025-11-20 00:13:57.512386 | TASK [include_role : start-zuul-console] 2025-11-20 00:13:57.531885 | controller | ok 2025-11-20 00:13:57.546823 | 2025-11-20 00:13:57.546931 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-20 00:13:57.995103 | controller | ok 2025-11-20 00:13:58.010914 | 2025-11-20 00:13:58.011243 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-20 00:13:58.999560 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-20 00:13:59.010572 | 2025-11-20 00:13:59.010805 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-20 00:13:59.554485 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.562007 | 2025-11-20 00:13:59.562155 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-20 00:13:59.606869 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.614249 | 2025-11-20 00:13:59.614344 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-20 00:13:59.638176 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.645105 | 2025-11-20 00:13:59.645219 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-20 00:13:59.669239 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.676282 | 2025-11-20 00:13:59.676441 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-20 00:13:59.702605 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.709512 | 2025-11-20 00:13:59.709640 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-20 00:13:59.737515 | controller | skipping: Conditional result was False 2025-11-20 00:13:59.753655 | 2025-11-20 00:13:59.753787 | TASK [Disable Fedora Modular] 2025-11-20 00:14:00.041632 | controller | changed 2025-11-20 00:14:00.048708 | 2025-11-20 00:14:00.048807 | TASK [Enable EPEL] 2025-11-20 00:14:00.085089 | controller | skipping: Conditional result was False 2025-11-20 00:14:00.100484 | 2025-11-20 00:14:00.100664 | TASK [Register the RHEL node] 2025-11-20 00:14:00.676611 | 2025-11-20 00:14:00.676799 | TASK [Show the subscription-manager status] 2025-11-20 00:14:01.267181 | controller | skipping: Conditional result was False 2025-11-20 00:14:01.287122 | 2025-11-20 00:14:01.287263 | TASK [Enable EPEL on RHEL] 2025-11-20 00:14:01.819283 | controller | skipping: Conditional result was False 2025-11-20 00:14:01.832237 | 2025-11-20 00:14:01.832393 | TASK [Install git and tox] 2025-11-20 00:15:25.529993 | controller | changed 2025-11-20 00:15:25.537252 | 2025-11-20 00:15:25.537373 | TASK [include_role : prepare-workspace] 2025-11-20 00:15:25.567797 | controller | ok 2025-11-20 00:15:25.599287 | 2025-11-20 00:15:25.599415 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-20 00:15:25.814541 | controller | ok 2025-11-20 00:15:25.823761 | 2025-11-20 00:15:25.823886 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-20 00:15:41.887008 | controller | Output suppressed because no_log was given 2025-11-20 00:15:41.942502 | 2025-11-20 00:15:41.942627 | TASK [include_role : prepare-workspace-openshift] 2025-11-20 00:15:41.959865 | controller | skipping: Conditional result was False 2025-11-20 00:15:41.989255 | 2025-11-20 00:15:41.989360 | PLAY [all:!appliance] 2025-11-20 00:15:42.009994 | 2025-11-20 00:15:42.010136 | TASK [Run add-build-sshkey role (RSA)] 2025-11-20 00:15:42.031047 | controller | ok 2025-11-20 00:15:42.054965 | 2025-11-20 00:15:42.055095 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-20 00:15:42.325740 | controller -> localhost | ok 2025-11-20 00:15:42.342836 | 2025-11-20 00:15:42.342993 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-20 00:15:42.367783 | controller | ok 2025-11-20 00:15:42.388130 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-20 00:15:42.397371 | 2025-11-20 00:15:42.397464 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-20 00:15:43.096206 | controller -> localhost | Generating public/private rsa key pair. 2025-11-20 00:15:43.096487 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_rsa. 2025-11-20 00:15:43.096524 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_rsa.pub. 2025-11-20 00:15:43.096551 | controller -> localhost | The key fingerprint is: 2025-11-20 00:15:43.096576 | controller -> localhost | SHA256:GAlSx8QSeowmUmQ/X4tp8EyS55UX4Sp3gyPld3xUIvM zuul-build-sshkey 2025-11-20 00:15:43.096599 | controller -> localhost | The key's randomart image is: 2025-11-20 00:15:43.096622 | controller -> localhost | +---[RSA 2048]----+ 2025-11-20 00:15:43.096644 | controller -> localhost | | .=.+=o o.o . .| 2025-11-20 00:15:43.096667 | controller -> localhost | | o *.+o. o . + o | 2025-11-20 00:15:43.096690 | controller -> localhost | |o + O.= = o E | 2025-11-20 00:15:43.096712 | controller -> localhost | |.o . @ X = . . | 2025-11-20 00:15:43.096733 | controller -> localhost | | % S + o . | 2025-11-20 00:15:43.096764 | controller -> localhost | | . + + o . | 2025-11-20 00:15:43.096793 | controller -> localhost | | | 2025-11-20 00:15:43.096818 | controller -> localhost | | | 2025-11-20 00:15:43.096840 | controller -> localhost | | | 2025-11-20 00:15:43.096864 | controller -> localhost | +----[SHA256]-----+ 2025-11-20 00:15:43.096942 | controller -> localhost | ok: Runtime: 0:00:00.187146 2025-11-20 00:15:43.106965 | 2025-11-20 00:15:43.107110 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-20 00:15:43.129977 | controller | ok 2025-11-20 00:15:43.141805 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-20 00:15:43.152082 | 2025-11-20 00:15:43.152185 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-20 00:15:43.166579 | controller | skipping: Conditional result was False 2025-11-20 00:15:43.173617 | 2025-11-20 00:15:43.173690 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-20 00:15:43.629007 | controller | changed 2025-11-20 00:15:43.642656 | 2025-11-20 00:15:43.642747 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-20 00:15:43.874127 | controller | ok 2025-11-20 00:15:43.884122 | 2025-11-20 00:15:43.884292 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-20 00:15:44.510048 | controller | changed 2025-11-20 00:15:44.516334 | 2025-11-20 00:15:44.516414 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-20 00:15:45.163883 | controller | changed 2025-11-20 00:15:45.181137 | 2025-11-20 00:15:45.181380 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-20 00:15:45.210904 | controller | skipping: Conditional result was False 2025-11-20 00:15:45.229622 | 2025-11-20 00:15:45.229851 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-20 00:15:45.779967 | controller -> localhost | changed 2025-11-20 00:15:45.808795 | 2025-11-20 00:15:45.808999 | TASK [add-build-sshkey : Add back temp key] 2025-11-20 00:15:46.122250 | controller -> localhost | Identity added: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_rsa (zuul-build-sshkey) 2025-11-20 00:15:46.122541 | controller -> localhost | ok: Runtime: 0:00:00.010661 2025-11-20 00:15:46.132932 | 2025-11-20 00:15:46.133123 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-20 00:20:46.056890 | controller | ok 2025-11-20 00:20:46.077029 | 2025-11-20 00:20:46.077147 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-20 00:20:46.117389 | controller | skipping: Conditional result was False 2025-11-20 00:20:46.167881 | 2025-11-20 00:20:46.168006 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-20 00:20:46.202225 | controller | ok 2025-11-20 00:20:46.221851 | 2025-11-20 00:20:46.221973 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-20 00:20:46.503502 | controller -> localhost | ok 2025-11-20 00:20:46.512050 | 2025-11-20 00:20:46.512158 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-20 00:20:46.546645 | controller | ok 2025-11-20 00:20:46.562770 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-20 00:20:46.572141 | 2025-11-20 00:20:46.572272 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-20 00:20:46.885805 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-20 00:20:46.886053 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_ecdsa. 2025-11-20 00:20:46.886102 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_ecdsa.pub. 2025-11-20 00:20:46.886135 | controller -> localhost | The key fingerprint is: 2025-11-20 00:20:46.886156 | controller -> localhost | SHA256:1HL6R0m5I/ywOCuRPQ4y3Hro6QQKxkbW4e6F2Y8ZtxI zuul-build-sshkey 2025-11-20 00:20:46.886175 | controller -> localhost | The key's randomart image is: 2025-11-20 00:20:46.886194 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-20 00:20:46.886212 | controller -> localhost | | . | 2025-11-20 00:20:46.886229 | controller -> localhost | | o . . . | 2025-11-20 00:20:46.886247 | controller -> localhost | | o o o o o | 2025-11-20 00:20:46.886264 | controller -> localhost | |+ . + . = . o | 2025-11-20 00:20:46.886282 | controller -> localhost | |.+.= E +S + = | 2025-11-20 00:20:46.886299 | controller -> localhost | |+...= % +o * . | 2025-11-20 00:20:46.886316 | controller -> localhost | |. ..O *o.o o | 2025-11-20 00:20:46.886334 | controller -> localhost | | .o.+ .o . | 2025-11-20 00:20:46.886351 | controller -> localhost | | o+. .. | 2025-11-20 00:20:46.886369 | controller -> localhost | +----[SHA256]-----+ 2025-11-20 00:20:46.886417 | controller -> localhost | ok: Runtime: 0:00:00.008656 2025-11-20 00:20:46.893689 | 2025-11-20 00:20:46.893813 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-20 00:20:46.924513 | controller | ok 2025-11-20 00:20:46.932803 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-20 00:20:46.942834 | 2025-11-20 00:20:46.942922 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-20 00:20:46.966969 | controller | skipping: Conditional result was False 2025-11-20 00:20:46.974392 | 2025-11-20 00:20:46.974470 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-20 00:20:47.252459 | controller | changed 2025-11-20 00:20:47.258531 | 2025-11-20 00:20:47.258606 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-20 00:20:47.517605 | controller | ok 2025-11-20 00:20:47.527894 | 2025-11-20 00:20:47.528041 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-20 00:20:48.132065 | controller | changed 2025-11-20 00:20:48.143115 | 2025-11-20 00:20:48.143247 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-20 00:20:48.786255 | controller | changed 2025-11-20 00:20:48.796196 | 2025-11-20 00:20:48.796293 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-20 00:20:48.825482 | controller | skipping: Conditional result was False 2025-11-20 00:20:48.841347 | 2025-11-20 00:20:48.841672 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-20 00:20:49.146243 | controller -> localhost | changed 2025-11-20 00:20:49.165081 | 2025-11-20 00:20:49.165198 | TASK [add-build-sshkey : Add back temp key] 2025-11-20 00:20:49.474774 | controller -> localhost | Identity added: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/bd8e6da99dad4242a3099f3ccf1e7b43_id_ecdsa (zuul-build-sshkey) 2025-11-20 00:20:49.475334 | controller -> localhost | ok: Runtime: 0:00:00.012796 2025-11-20 00:20:49.492523 | 2025-11-20 00:20:49.492699 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-20 00:20:49.709927 | controller | ok 2025-11-20 00:20:49.722224 | 2025-11-20 00:20:49.722401 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-20 00:20:49.759591 | controller | skipping: Conditional result was False 2025-11-20 00:20:49.779651 | 2025-11-20 00:20:49.779800 | TASK [include_role : remove-zuul-sshkey] 2025-11-20 00:20:49.805608 | controller | skipping: Conditional result was False 2025-11-20 00:20:49.811890 | 2025-11-20 00:20:49.812109 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-20 00:20:50.037824 | controller | ok: "logs" 2025-11-20 00:20:50.038144 | controller | ok: All items complete 2025-11-20 00:20:50.038182 | 2025-11-20 00:20:50.246710 | controller | ok: "artifacts" 2025-11-20 00:20:50.446287 | controller | ok: "docs" 2025-11-20 00:20:50.470903 | 2025-11-20 00:20:50.471131 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-20 00:20:50.721288 | controller | changed: "logs" 2025-11-20 00:20:50.931336 | controller | changed: "artifacts" 2025-11-20 00:20:51.145267 | controller | changed: "docs" 2025-11-20 00:20:51.203958 | 2025-11-20 00:20:51.204128 | PLAY RECAP 2025-11-20 00:20:51.204196 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-20 00:20:51.204232 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-20 00:20:51.204257 | 2025-11-20 00:20:51.329338 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-20 00:20:51.330188 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-20 00:20:51.985228 | 2025-11-20 00:20:51.985337 | PLAY [all] 2025-11-20 00:20:52.014209 | 2025-11-20 00:20:52.014372 | TASK [Install binary dependencies] 2025-11-20 00:20:52.095901 | controller | ok 2025-11-20 00:20:52.126191 | 2025-11-20 00:20:52.126327 | TASK [bindep : Include find tasks] 2025-11-20 00:20:52.166895 | controller | ok 2025-11-20 00:20:52.183908 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-20 00:20:52.190683 | 2025-11-20 00:20:52.190758 | TASK [bindep : Look for bindep.txt] 2025-11-20 00:20:52.819211 | controller | ok 2025-11-20 00:20:52.835168 | 2025-11-20 00:20:52.835355 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:20:52.861662 | controller | skipping: Conditional result was False 2025-11-20 00:20:52.870952 | 2025-11-20 00:20:52.871109 | TASK [bindep : Look for other-requirements.txt] 2025-11-20 00:20:53.101435 | controller | ok 2025-11-20 00:20:53.114208 | 2025-11-20 00:20:53.114355 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:20:53.141820 | controller | skipping: Conditional result was False 2025-11-20 00:20:53.150853 | 2025-11-20 00:20:53.150945 | TASK [bindep : Look for bindep fallback file] 2025-11-20 00:20:53.176169 | controller | skipping: Conditional result was False 2025-11-20 00:20:53.191377 | 2025-11-20 00:20:53.191539 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:20:53.218933 | controller | skipping: Conditional result was False 2025-11-20 00:20:53.232140 | 2025-11-20 00:20:53.232276 | TASK [bindep : Include bindep tasks] 2025-11-20 00:20:53.258939 | controller | skipping: Conditional result was False 2025-11-20 00:20:53.272057 | 2025-11-20 00:20:53.272190 | TASK [bindep : Include install tasks] 2025-11-20 00:20:53.299093 | controller | skipping: Conditional result was False 2025-11-20 00:20:53.315420 | 2025-11-20 00:20:53.315626 | LOOP [bindep : Include package tasks] 2025-11-20 00:20:53.399583 | 2025-11-20 00:20:53.399876 | TASK [Run test-setup role] 2025-11-20 00:20:53.435744 | controller | ok 2025-11-20 00:20:53.466864 | 2025-11-20 00:20:53.467090 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-20 00:20:53.681087 | controller | ok 2025-11-20 00:20:53.697161 | 2025-11-20 00:20:53.697315 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-20 00:20:54.247316 | controller | skipping: Conditional result was False 2025-11-20 00:20:54.287155 | 2025-11-20 00:20:54.287346 | PLAY RECAP 2025-11-20 00:20:54.287399 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-20 00:20:54.287420 | 2025-11-20 00:20:54.555667 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-20 00:20:54.556879 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-20 00:20:55.300160 | 2025-11-20 00:20:55.300305 | PLAY [controller] 2025-11-20 00:20:55.321863 | 2025-11-20 00:20:55.321977 | TASK [Create the /root directory] 2025-11-20 00:20:55.979794 | controller | ok 2025-11-20 00:20:55.988455 | 2025-11-20 00:20:55.988559 | TASK [Install glibc-langpack-en] 2025-11-20 00:20:59.997933 | controller | ok: Nothing to do 2025-11-20 00:21:00.011229 | 2025-11-20 00:21:00.011369 | TASK [Ensure controller directory exists] 2025-11-20 00:21:00.237231 | controller | changed 2025-11-20 00:21:00.243603 | 2025-11-20 00:21:00.243673 | TASK [Install container runtime] 2025-11-20 00:21:00.303728 | controller | ok 2025-11-20 00:21:00.361415 | 2025-11-20 00:21:00.361583 | LOOP [ensure-podman : Find distribution installation] 2025-11-20 00:21:00.416709 | controller | ok: "/var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-11-20 00:21:00.436847 | controller | included: /var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-11-20 00:21:00.448684 | 2025-11-20 00:21:00.448820 | TASK [ensure-podman : Install podman (RedHat)] 2025-11-20 00:22:05.947725 | controller | changed 2025-11-20 00:22:05.956588 | 2025-11-20 00:22:05.956701 | TASK [ensure-podman : Fetch podman version] 2025-11-20 00:22:06.514968 | controller | Client: Podman Engine 2025-11-20 00:22:06.515105 | controller | Version: 4.6.2 2025-11-20 00:22:06.515168 | controller | API Version: 4.6.2 2025-11-20 00:22:06.515259 | controller | Go Version: go1.19.12 2025-11-20 00:22:06.515321 | controller | Built: Mon Aug 28 19:38:31 2023 2025-11-20 00:22:06.515367 | controller | OS/Arch: linux/amd64 2025-11-20 00:22:07.000904 | controller | ok: Runtime: 0:00:00.180588 2025-11-20 00:22:07.016867 | 2025-11-20 00:22:07.017114 | TASK [ensure-podman : Print podman version installed] 2025-11-20 00:22:07.059587 | Podman version: Client: Podman Engine 2025-11-20 00:22:07.059891 | Version: 4.6.2 2025-11-20 00:22:07.059965 | API Version: 4.6.2 2025-11-20 00:22:07.060065 | Go Version: go1.19.12 2025-11-20 00:22:07.060120 | Built: Mon Aug 28 19:38:31 2023 2025-11-20 00:22:07.060163 | OS/Arch: linux/amd64 2025-11-20 00:22:07.073822 | 2025-11-20 00:22:07.074066 | TASK [ensure-podman : Validate podman engine] 2025-11-20 00:22:07.621270 | controller | skipping: Conditional result was False 2025-11-20 00:22:07.629157 | 2025-11-20 00:22:07.629315 | TASK [ensure-podman : Set up docker compatability socket] 2025-11-20 00:22:07.643808 | controller | skipping: Conditional result was False 2025-11-20 00:22:07.660218 | 2025-11-20 00:22:07.660355 | TASK [Ensure python3.8 is present] 2025-11-20 00:22:07.685731 | controller | skipping: Conditional result was False 2025-11-20 00:22:07.694402 | 2025-11-20 00:22:07.694515 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-20 00:22:07.716691 | controller | ok 2025-11-20 00:22:07.744665 | 2025-11-20 00:22:07.744802 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-20 00:22:09.084286 | controller | ok: Nothing to do 2025-11-20 00:22:09.104724 | 2025-11-20 00:22:09.105243 | TASK [our-ensure-python : Also install python3-devel] 2025-11-20 00:22:18.021822 | controller | changed 2025-11-20 00:22:18.041729 | 2025-11-20 00:22:18.041853 | TASK [Run ensure-virtualenv role] 2025-11-20 00:22:18.065274 | controller | ok 2025-11-20 00:22:18.094098 | 2025-11-20 00:22:18.094238 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-20 00:22:18.383773 | controller | /usr/bin/virtualenv 2025-11-20 00:22:18.672070 | controller | ok: Runtime: 0:00:00.005318 2025-11-20 00:22:18.683731 | 2025-11-20 00:22:18.683911 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-20 00:22:18.718577 | controller | skipping: Conditional result was False 2025-11-20 00:22:18.718989 | controller | ok: All items complete 2025-11-20 00:22:18.719067 | 2025-11-20 00:22:18.743924 | 2025-11-20 00:22:18.744220 | TASK [Find the full path of the Python interpreter] 2025-11-20 00:22:18.970521 | controller | /usr/bin/python3 2025-11-20 00:22:19.289619 | controller | ok 2025-11-20 00:22:19.304005 | 2025-11-20 00:22:19.304208 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-20 00:22:20.109394 | controller | created virtual environment CPython3.11.0.final.0-64 in 442ms 2025-11-20 00:22:20.125597 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-20 00:22:20.125635 | 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) 2025-11-20 00:22:20.125644 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-20 00:22:20.125659 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-20 00:22:20.363504 | controller | changed 2025-11-20 00:22:20.378967 | 2025-11-20 00:22:20.379230 | TASK [Set selinux package] 2025-11-20 00:22:20.412705 | controller | ok 2025-11-20 00:22:20.428944 | 2025-11-20 00:22:20.429136 | TASK [Set selinux package (Fedora)] 2025-11-20 00:22:20.466927 | controller | ok 2025-11-20 00:22:20.478387 | 2025-11-20 00:22:20.478488 | TASK [Install selinux into virtualenv] 2025-11-20 00:23:21.774979 | controller | Collecting selinux-please-lie-to-me 2025-11-20 00:23:34.167841 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-20 00:23:34.472435 | controller | Collecting setuptools<50.0.0 2025-11-20 00:23:34.581989 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-20 00:23:34.620382 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 24.5 MB/s eta 0:00:00 2025-11-20 00:23:34.702459 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-20 00:23:34.702673 | controller | Attempting uninstall: setuptools 2025-11-20 00:23:34.705151 | controller | Found existing installation: setuptools 62.6.0 2025-11-20 00:23:34.769916 | controller | Uninstalling setuptools-62.6.0: 2025-11-20 00:23:34.778159 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-20 00:23:35.147595 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-20 00:23:46.569984 | controller | 2025-11-20 00:23:46.662438 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-20 00:23:46.662469 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-20 00:23:47.096248 | controller | ok: Runtime: 0:01:25.957761 2025-11-20 00:23:47.111490 | 2025-11-20 00:23:47.111667 | TASK [Install pytest-forked into virtualenv] 2025-11-20 00:24:11.994351 | controller | Collecting pytest-forked 2025-11-20 00:24:24.292234 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-20 00:24:24.358906 | controller | Collecting py 2025-11-20 00:24:24.419071 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-20 00:24:24.448211 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.7 MB/s eta 0:00:00 2025-11-20 00:24:24.557664 | controller | Collecting pytest>=3.10 2025-11-20 00:24:24.603620 | controller | Downloading pytest-9.0.1-py3-none-any.whl (373 kB) 2025-11-20 00:24:24.625147 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.7/373.7 kB 20.8 MB/s eta 0:00:00 2025-11-20 00:24:24.690400 | controller | Collecting iniconfig>=1.0.1 2025-11-20 00:24:24.721403 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-11-20 00:24:24.773597 | controller | Collecting packaging>=22 2025-11-20 00:24:24.790048 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-20 00:24:24.802078 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 7.5 MB/s eta 0:00:00 2025-11-20 00:24:24.850338 | controller | Collecting pluggy<2,>=1.5 2025-11-20 00:24:24.898513 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-20 00:24:24.977438 | controller | Collecting pygments>=2.7.2 2025-11-20 00:24:25.030333 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-20 00:24:25.063748 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 42.5 MB/s eta 0:00:00 2025-11-20 00:24:25.134514 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-11-20 00:24:26.337014 | 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.1 pytest-forked-1.6.0 2025-11-20 00:24:26.348048 | controller | 2025-11-20 00:24:26.457375 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-20 00:24:26.457409 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-20 00:24:26.683350 | controller | ok: Runtime: 0:00:39.095426 2025-11-20 00:24:26.692009 | 2025-11-20 00:24:26.692175 | TASK [Update pip] 2025-11-20 00:24:27.267474 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-11-20 00:24:39.839174 | controller | Collecting pip 2025-11-20 00:24:52.220294 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-20 00:24:52.277118 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 34.8 MB/s eta 0:00:00 2025-11-20 00:24:52.340725 | controller | Installing collected packages: pip 2025-11-20 00:24:52.340863 | controller | Attempting uninstall: pip 2025-11-20 00:24:52.342999 | controller | Found existing installation: pip 22.2.2 2025-11-20 00:24:52.482143 | controller | Uninstalling pip-22.2.2: 2025-11-20 00:24:52.497080 | controller | Successfully uninstalled pip-22.2.2 2025-11-20 00:24:53.287674 | controller | Successfully installed pip-25.3 2025-11-20 00:24:53.795289 | controller | ok: Runtime: 0:00:26.390840 2025-11-20 00:24:53.801312 | 2025-11-20 00:24:53.801395 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-11-20 00:24:54.028974 | controller | changed 2025-11-20 00:24:54.037244 | 2025-11-20 00:24:54.037390 | TASK [Install ansible into virtualenv] 2025-11-20 00:24:54.572198 | controller | Processing ./src/github.com/ansible/ansible 2025-11-20 00:24:54.575532 | controller | Installing build dependencies: started 2025-11-20 00:25:15.423640 | controller | Installing build dependencies: finished with status 'done' 2025-11-20 00:25:15.424966 | controller | Getting requirements to build wheel: started 2025-11-20 00:25:16.161845 | controller | Getting requirements to build wheel: finished with status 'done' 2025-11-20 00:25:16.162752 | controller | Preparing metadata (pyproject.toml): started 2025-11-20 00:25:16.636363 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-11-20 00:25:16.639277 | 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. 2025-11-20 00:25:16.641679 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-11-20 00:25:17.097397 | controller | ERROR 2025-11-20 00:25:17.097744 | controller | { 2025-11-20 00:25:17.097832 | controller | "delta": "0:00:22.437644", 2025-11-20 00:25:17.097886 | controller | "end": "2025-11-20 00:25:16.699765", 2025-11-20 00:25:17.097931 | controller | "msg": "non-zero return code", 2025-11-20 00:25:17.097997 | controller | "rc": 1, 2025-11-20 00:25:17.098096 | controller | "start": "2025-11-20 00:24:54.262121" 2025-11-20 00:25:17.098146 | controller | } failure 2025-11-20 00:25:17.100947 | 2025-11-20 00:25:17.101155 | PLAY RECAP 2025-11-20 00:25:17.101308 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-11-20 00:25:17.101390 | 2025-11-20 00:25:17.246302 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-20 00:25:17.248909 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-20 00:25:17.922171 | 2025-11-20 00:25:17.922293 | PLAY [all] 2025-11-20 00:25:17.948451 | 2025-11-20 00:25:17.948603 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-20 00:25:18.361412 | controller | changed: non-zero return code 2025-11-20 00:25:18.370970 | 2025-11-20 00:25:18.371179 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-20 00:25:18.397343 | controller | skipping: Conditional result was False 2025-11-20 00:25:18.404694 | 2025-11-20 00:25:18.404829 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-20 00:25:18.439362 | 2025-11-20 00:25:18.439576 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-20 00:25:18.466711 | 2025-11-20 00:25:18.466897 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-20 00:25:18.491649 | controller | skipping: Conditional result was False 2025-11-20 00:25:18.502269 | 2025-11-20 00:25:18.502421 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-20 00:25:18.536901 | 2025-11-20 00:25:18.537137 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-20 00:25:18.562460 | controller | skipping: Conditional result was False 2025-11-20 00:25:18.573443 | 2025-11-20 00:25:18.573580 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-20 00:25:18.599213 | controller | skipping: Conditional result was False 2025-11-20 00:25:18.608437 | 2025-11-20 00:25:18.608558 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-20 00:25:18.633976 | controller | skipping: Conditional result was False 2025-11-20 00:25:18.662544 | 2025-11-20 00:25:18.662661 | PLAY RECAP 2025-11-20 00:25:18.662706 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-20 00:25:18.662727 | 2025-11-20 00:25:18.783934 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-20 00:25:18.784776 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-20 00:25:19.446741 | 2025-11-20 00:25:19.446883 | PLAY [all:!appliance*] 2025-11-20 00:25:19.471446 | 2025-11-20 00:25:19.471609 | TASK [unregister the node] 2025-11-20 00:25:20.003938 | controller | skipping: Conditional result was False 2025-11-20 00:25:20.010314 | 2025-11-20 00:25:20.010429 | TASK [include_role : fetch-output] 2025-11-20 00:25:20.064782 | controller | ok 2025-11-20 00:25:20.106930 | 2025-11-20 00:25:20.107100 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-20 00:25:20.152902 | controller | skipping: Conditional result was False 2025-11-20 00:25:20.159473 | 2025-11-20 00:25:20.159587 | TASK [fetch-output : Set log path for single node] 2025-11-20 00:25:20.202555 | controller | ok 2025-11-20 00:25:20.213513 | 2025-11-20 00:25:20.213734 | LOOP [fetch-output : Ensure local output dirs] 2025-11-20 00:25:20.691659 | controller -> localhost | ok: "/var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/logs" 2025-11-20 00:25:20.983884 | controller -> localhost | changed: "/var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/artifacts" 2025-11-20 00:25:21.205047 | controller -> localhost | changed: "/var/lib/zuul/builds/bd8e6da99dad4242a3099f3ccf1e7b43/work/docs" 2025-11-20 00:25:21.221505 | 2025-11-20 00:25:21.221751 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-20 00:25:21.922887 | controller | changed: 2025-11-20 00:25:21.923298 | controller | .d..t...... ./ 2025-11-20 00:25:21.923354 | controller | cd+++++++++ controller/ 2025-11-20 00:25:21.923404 | controller | changed: All items complete 2025-11-20 00:25:21.923434 | 2025-11-20 00:25:22.501717 | controller | changed: .d..t...... ./ 2025-11-20 00:25:23.041494 | controller | changed: .d..t...... ./ 2025-11-20 00:25:23.071264 | 2025-11-20 00:25:23.071411 | TASK [include_role : fetch-output-openshift] 2025-11-20 00:25:23.097292 | controller | skipping: Conditional result was False 2025-11-20 00:25:23.104538 | 2025-11-20 00:25:23.104644 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-20 00:25:23.141866 | controller | skipping: Conditional result was False 2025-11-20 00:25:23.155390 | controller | skipping: Conditional result was False 2025-11-20 00:25:23.191359 | 2025-11-20 00:25:23.191466 | PLAY [localhost] 2025-11-20 00:25:23.206403 | 2025-11-20 00:25:23.206513 | TASK [Run Zuul manifest role] 2025-11-20 00:25:23.224987 | localhost | ok 2025-11-20 00:25:23.260493 | 2025-11-20 00:25:23.260608 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-20 00:25:23.650317 | localhost | changed 2025-11-20 00:25:23.664502 | 2025-11-20 00:25:23.664592 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-20 00:25:23.713978 | localhost | ok 2025-11-20 00:25:23.730042 | 2025-11-20 00:25:23.730291 | TASK [Set zuul-log-path fact] 2025-11-20 00:25:23.753791 | localhost | ok 2025-11-20 00:25:23.800195 | 2025-11-20 00:25:23.800339 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-20 00:25:23.842380 | localhost | ok 2025-11-20 00:25:23.853081 | 2025-11-20 00:25:23.853222 | LOOP [Run upload-logs-swift role] 2025-11-20 00:25:23.902282 | localhost | Output suppressed because no_log was given 2025-11-20 00:25:23.956060 | 2025-11-20 00:25:23.956208 | TASK [Set zuul-log-path fact] 2025-11-20 00:25:23.981933 | localhost | skipping: Conditional result was False 2025-11-20 00:25:23.987335 | 2025-11-20 00:25:23.987429 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-20 00:25:24.508867 | localhost -> localhost | ok: Runtime: 0:00:00.005052 2025-11-20 00:25:24.555854 | 2025-11-20 00:25:24.555969 | TASK [upload-logs-swift : Upload logs to swift]