2025-12-23 00:06:53.241697 | Job console starting... 2025-12-23 00:06:53.253101 | Updating repositories 2025-12-23 00:06:53.459367 | Preparing job workspace 2025-12-23 00:06:56.930966 | Running Ansible setup... 2025-12-23 00:07:02.492117 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-23 00:07:03.162261 | 2025-12-23 00:07:03.162392 | PLAY [localhost] 2025-12-23 00:07:03.170776 | 2025-12-23 00:07:03.170855 | TASK [Gathering Facts] 2025-12-23 00:07:04.141217 | localhost | ok 2025-12-23 00:07:04.165059 | 2025-12-23 00:07:04.165223 | TASK [Setup log path fact] 2025-12-23 00:07:04.186567 | localhost | ok 2025-12-23 00:07:04.204992 | 2025-12-23 00:07:04.205117 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-23 00:07:04.245980 | localhost | ok 2025-12-23 00:07:04.257634 | 2025-12-23 00:07:04.257762 | TASK [emit-job-header : Print job information] 2025-12-23 00:07:04.306577 | # Job Information 2025-12-23 00:07:04.306727 | Ansible Version: 2.15.12 2025-12-23 00:07:04.306763 | Job: ansible-test-sanity-docker-milestone 2025-12-23 00:07:04.306784 | Pipeline: periodic 2025-12-23 00:07:04.306802 | Executor: ze02.softwarefactory-project.io 2025-12-23 00:07:04.306819 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-23 00:07:04.306839 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/2dc/ansible/2dc18e1c3b254f449bb2a3c94973a002/ 2025-12-23 00:07:04.306858 | Event ID: 53716c5a236c4d5eab91d4bd51d64c9b 2025-12-23 00:07:04.310809 | 2025-12-23 00:07:04.310875 | LOOP [emit-job-header : Print node information] 2025-12-23 00:07:04.417849 | localhost | ok: 2025-12-23 00:07:04.418055 | localhost | # Node Information 2025-12-23 00:07:04.418082 | localhost | Inventory Hostname: controller 2025-12-23 00:07:04.418103 | localhost | Hostname: np0005569176 2025-12-23 00:07:04.418122 | localhost | Username: zuul 2025-12-23 00:07:04.418153 | localhost | Distro: Fedora 37 2025-12-23 00:07:04.418245 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-23 00:07:04.418279 | localhost | Region: ca-ymq-1 2025-12-23 00:07:04.418298 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-23 00:07:04.418315 | localhost | Product Name: OpenStack Nova 2025-12-23 00:07:04.418333 | localhost | Interface IP: 162.253.55.200 2025-12-23 00:07:04.437738 | 2025-12-23 00:07:04.437910 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-23 00:07:04.893358 | localhost -> localhost | changed 2025-12-23 00:07:04.901372 | 2025-12-23 00:07:04.901486 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-23 00:07:05.813106 | localhost -> localhost | changed 2025-12-23 00:07:05.843549 | 2025-12-23 00:07:05.843726 | PLAY [all:!appliance*] 2025-12-23 00:07:05.863452 | 2025-12-23 00:07:05.863550 | TASK [include_role : start-zuul-console] 2025-12-23 00:07:05.884233 | controller | ok 2025-12-23 00:07:05.899944 | 2025-12-23 00:07:05.900022 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-23 00:07:06.315373 | controller | ok 2025-12-23 00:07:06.328121 | 2025-12-23 00:07:06.328211 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-23 00:07:40.469390 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-23 00:07:40.487856 | 2025-12-23 00:07:40.487997 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-23 00:07:41.032124 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.047688 | 2025-12-23 00:07:41.047839 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-23 00:07:41.074722 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.089842 | 2025-12-23 00:07:41.089995 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-23 00:07:41.116430 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.131056 | 2025-12-23 00:07:41.131223 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-23 00:07:41.157986 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.173252 | 2025-12-23 00:07:41.173415 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-23 00:07:41.200954 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.215276 | 2025-12-23 00:07:41.215432 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-23 00:07:41.242418 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.272107 | 2025-12-23 00:07:41.272222 | TASK [Disable Fedora Modular] 2025-12-23 00:07:41.649920 | controller | changed 2025-12-23 00:07:41.658205 | 2025-12-23 00:07:41.658292 | TASK [Enable EPEL] 2025-12-23 00:07:41.683483 | controller | skipping: Conditional result was False 2025-12-23 00:07:41.693500 | 2025-12-23 00:07:41.693611 | TASK [Register the RHEL node] 2025-12-23 00:07:42.251909 | 2025-12-23 00:07:42.252097 | TASK [Show the subscription-manager status] 2025-12-23 00:07:42.804486 | controller | skipping: Conditional result was False 2025-12-23 00:07:42.813985 | 2025-12-23 00:07:42.814080 | TASK [Enable EPEL on RHEL] 2025-12-23 00:07:43.373497 | controller | skipping: Conditional result was False 2025-12-23 00:07:43.382365 | 2025-12-23 00:07:43.382458 | TASK [Install git and tox] 2025-12-23 00:08:45.696395 | controller | changed 2025-12-23 00:08:45.702779 | 2025-12-23 00:08:45.702840 | TASK [include_role : prepare-workspace] 2025-12-23 00:08:45.722549 | controller | ok 2025-12-23 00:08:45.744744 | 2025-12-23 00:08:45.744864 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-23 00:08:46.006595 | controller | ok 2025-12-23 00:08:46.021122 | 2025-12-23 00:08:46.021284 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-23 00:08:59.850648 | controller | Output suppressed because no_log was given 2025-12-23 00:08:59.863200 | 2025-12-23 00:08:59.863263 | TASK [include_role : prepare-workspace-openshift] 2025-12-23 00:08:59.888904 | controller | skipping: Conditional result was False 2025-12-23 00:08:59.910716 | 2025-12-23 00:08:59.910769 | PLAY [all:!appliance] 2025-12-23 00:08:59.926885 | 2025-12-23 00:08:59.926945 | TASK [Run add-build-sshkey role (RSA)] 2025-12-23 00:08:59.956086 | controller | ok 2025-12-23 00:08:59.970802 | 2025-12-23 00:08:59.970865 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-23 00:09:00.177075 | controller -> localhost | ok 2025-12-23 00:09:00.225912 | 2025-12-23 00:09:00.226023 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-23 00:09:00.256490 | controller | ok 2025-12-23 00:09:00.271771 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-23 00:09:00.278115 | 2025-12-23 00:09:00.278178 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-23 00:09:00.748881 | controller -> localhost | Generating public/private rsa key pair. 2025-12-23 00:09:00.749055 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_rsa. 2025-12-23 00:09:00.749100 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_rsa.pub. 2025-12-23 00:09:00.749127 | controller -> localhost | The key fingerprint is: 2025-12-23 00:09:00.749148 | controller -> localhost | SHA256:F9YszLkpl+JhGNZa++TPSIdsQem9nxZlk1d7lPy48J8 zuul-build-sshkey 2025-12-23 00:09:00.749168 | controller -> localhost | The key's randomart image is: 2025-12-23 00:09:00.749187 | controller -> localhost | +---[RSA 2048]----+ 2025-12-23 00:09:00.749205 | controller -> localhost | | . .| 2025-12-23 00:09:00.749223 | controller -> localhost | | . o = oo| 2025-12-23 00:09:00.749241 | controller -> localhost | | o o X o o=| 2025-12-23 00:09:00.749259 | controller -> localhost | | . = = B. .+*| 2025-12-23 00:09:00.749277 | controller -> localhost | | o S X .o ++| 2025-12-23 00:09:00.749302 | controller -> localhost | | o @ o .+ | 2025-12-23 00:09:00.749324 | controller -> localhost | | . B o o.| 2025-12-23 00:09:00.749343 | controller -> localhost | | o = ..E.| 2025-12-23 00:09:00.749361 | controller -> localhost | | . o.o | 2025-12-23 00:09:00.749382 | controller -> localhost | +----[SHA256]-----+ 2025-12-23 00:09:00.749428 | controller -> localhost | ok: Runtime: 0:00:00.057327 2025-12-23 00:09:00.756154 | 2025-12-23 00:09:00.756219 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-23 00:09:00.786883 | controller | ok 2025-12-23 00:09:00.796993 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-23 00:09:00.806024 | 2025-12-23 00:09:00.806086 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-23 00:09:00.831086 | controller | skipping: Conditional result was False 2025-12-23 00:09:00.838258 | 2025-12-23 00:09:00.838329 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-23 00:09:01.224465 | controller | changed 2025-12-23 00:09:01.233442 | 2025-12-23 00:09:01.233540 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-23 00:09:01.486271 | controller | ok 2025-12-23 00:09:01.493575 | 2025-12-23 00:09:01.493688 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-23 00:09:02.200058 | controller | changed 2025-12-23 00:09:02.211563 | 2025-12-23 00:09:02.211655 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-23 00:09:02.881243 | controller | changed 2025-12-23 00:09:02.891886 | 2025-12-23 00:09:02.892223 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-23 00:09:02.920962 | controller | skipping: Conditional result was False 2025-12-23 00:09:02.934413 | 2025-12-23 00:09:02.934607 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-23 00:09:03.505172 | controller -> localhost | changed 2025-12-23 00:09:03.522977 | 2025-12-23 00:09:03.523115 | TASK [add-build-sshkey : Add back temp key] 2025-12-23 00:09:03.966970 | controller -> localhost | Identity added: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_rsa (zuul-build-sshkey) 2025-12-23 00:09:03.967172 | controller -> localhost | ok: Runtime: 0:00:00.010464 2025-12-23 00:09:03.974315 | 2025-12-23 00:09:03.974379 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-23 00:09:04.399648 | controller | ok 2025-12-23 00:09:04.406414 | 2025-12-23 00:09:04.406740 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-23 00:09:04.431817 | controller | skipping: Conditional result was False 2025-12-23 00:09:04.446468 | 2025-12-23 00:09:04.446746 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-23 00:09:04.468207 | controller | ok 2025-12-23 00:09:04.485957 | 2025-12-23 00:09:04.486024 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-23 00:09:04.724450 | controller -> localhost | ok 2025-12-23 00:09:04.731216 | 2025-12-23 00:09:04.731280 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-23 00:09:04.761717 | controller | ok 2025-12-23 00:09:04.775989 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-23 00:09:04.784970 | 2025-12-23 00:09:04.785072 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-23 00:09:05.086968 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-23 00:09:05.087136 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_ecdsa. 2025-12-23 00:09:05.087164 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_ecdsa.pub. 2025-12-23 00:09:05.087192 | controller -> localhost | The key fingerprint is: 2025-12-23 00:09:05.087212 | controller -> localhost | SHA256:YjW01xTpl2YcvRbUH/lYKKID6RcBjR5pNmbqKfT0kBM zuul-build-sshkey 2025-12-23 00:09:05.087231 | controller -> localhost | The key's randomart image is: 2025-12-23 00:09:05.087249 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-23 00:09:05.087266 | controller -> localhost | | .*o. oo.+o| 2025-12-23 00:09:05.087283 | controller -> localhost | | E %.o..oo o++| 2025-12-23 00:09:05.087305 | controller -> localhost | | @ ++o.o.o =*| 2025-12-23 00:09:05.087329 | controller -> localhost | | . * o.+o . Boo| 2025-12-23 00:09:05.087353 | controller -> localhost | | . + =o.S. +. | 2025-12-23 00:09:05.087373 | controller -> localhost | | . +... | 2025-12-23 00:09:05.087408 | controller -> localhost | | . | 2025-12-23 00:09:05.087427 | controller -> localhost | | | 2025-12-23 00:09:05.087444 | controller -> localhost | | | 2025-12-23 00:09:05.087461 | controller -> localhost | +----[SHA256]-----+ 2025-12-23 00:09:05.087521 | controller -> localhost | ok: Runtime: 0:00:00.013420 2025-12-23 00:09:05.094526 | 2025-12-23 00:09:05.094600 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-23 00:09:05.125943 | controller | ok 2025-12-23 00:09:05.144855 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-23 00:09:05.169435 | 2025-12-23 00:09:05.169553 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-23 00:09:05.208095 | controller | skipping: Conditional result was False 2025-12-23 00:09:05.218066 | 2025-12-23 00:09:05.218181 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-23 00:09:05.500042 | controller | changed 2025-12-23 00:09:05.507085 | 2025-12-23 00:09:05.507147 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-23 00:09:05.741895 | controller | ok 2025-12-23 00:09:05.753192 | 2025-12-23 00:09:05.753284 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-23 00:09:06.430549 | controller | changed 2025-12-23 00:09:06.436616 | 2025-12-23 00:09:06.436713 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-23 00:09:07.125077 | controller | changed 2025-12-23 00:09:07.140220 | 2025-12-23 00:09:07.140359 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-23 00:09:07.155440 | controller | skipping: Conditional result was False 2025-12-23 00:09:07.165315 | 2025-12-23 00:09:07.165406 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-23 00:09:07.435420 | controller -> localhost | changed 2025-12-23 00:09:07.451076 | 2025-12-23 00:09:07.451171 | TASK [add-build-sshkey : Add back temp key] 2025-12-23 00:09:07.730699 | controller -> localhost | Identity added: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/2dc18e1c3b254f449bb2a3c94973a002_id_ecdsa (zuul-build-sshkey) 2025-12-23 00:09:07.730915 | controller -> localhost | ok: Runtime: 0:00:00.023327 2025-12-23 00:09:07.738017 | 2025-12-23 00:09:07.738089 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-23 00:09:07.944641 | controller | ok 2025-12-23 00:09:07.950648 | 2025-12-23 00:09:07.950726 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-23 00:09:07.974245 | controller | skipping: Conditional result was False 2025-12-23 00:09:07.988582 | 2025-12-23 00:09:07.988646 | TASK [include_role : remove-zuul-sshkey] 2025-12-23 00:09:08.002992 | controller | skipping: Conditional result was False 2025-12-23 00:09:08.010416 | 2025-12-23 00:09:08.010479 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-23 00:09:08.228326 | controller | ok: "logs" 2025-12-23 00:09:08.228572 | controller | ok: All items complete 2025-12-23 00:09:08.228600 | 2025-12-23 00:09:08.484768 | controller | ok: "artifacts" 2025-12-23 00:09:08.638791 | controller | ok: "docs" 2025-12-23 00:09:08.656003 | 2025-12-23 00:09:08.656090 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-23 00:09:08.902789 | controller | changed: "logs" 2025-12-23 00:09:09.097575 | controller | changed: "artifacts" 2025-12-23 00:09:09.288286 | controller | changed: "docs" 2025-12-23 00:09:09.321179 | 2025-12-23 00:09:09.321239 | PLAY RECAP 2025-12-23 00:09:09.321279 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-23 00:09:09.321304 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-23 00:09:09.321321 | 2025-12-23 00:09:09.452558 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-23 00:09:09.453453 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-23 00:09:10.023591 | 2025-12-23 00:09:10.023757 | PLAY [all] 2025-12-23 00:09:10.047441 | 2025-12-23 00:09:10.047575 | TASK [Install binary dependencies] 2025-12-23 00:09:10.108336 | controller | ok 2025-12-23 00:09:10.134355 | 2025-12-23 00:09:10.134468 | TASK [bindep : Include find tasks] 2025-12-23 00:09:10.165233 | controller | ok 2025-12-23 00:09:10.175911 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-23 00:09:10.182993 | 2025-12-23 00:09:10.183057 | TASK [bindep : Look for bindep.txt] 2025-12-23 00:09:10.533560 | controller | ok 2025-12-23 00:09:10.542702 | 2025-12-23 00:09:10.542800 | TASK [bindep : Define bindep_file fact] 2025-12-23 00:09:10.568955 | controller | skipping: Conditional result was False 2025-12-23 00:09:10.579113 | 2025-12-23 00:09:10.579205 | TASK [bindep : Look for other-requirements.txt] 2025-12-23 00:09:10.801478 | controller | ok 2025-12-23 00:09:10.814470 | 2025-12-23 00:09:10.814611 | TASK [bindep : Define bindep_file fact] 2025-12-23 00:09:10.856274 | controller | skipping: Conditional result was False 2025-12-23 00:09:10.865869 | 2025-12-23 00:09:10.865969 | TASK [bindep : Look for bindep fallback file] 2025-12-23 00:09:10.908394 | controller | skipping: Conditional result was False 2025-12-23 00:09:10.919975 | 2025-12-23 00:09:10.920085 | TASK [bindep : Define bindep_file fact] 2025-12-23 00:09:10.946843 | controller | skipping: Conditional result was False 2025-12-23 00:09:10.953696 | 2025-12-23 00:09:10.953767 | TASK [bindep : Include bindep tasks] 2025-12-23 00:09:10.978770 | controller | skipping: Conditional result was False 2025-12-23 00:09:10.984993 | 2025-12-23 00:09:10.985057 | TASK [bindep : Include install tasks] 2025-12-23 00:09:11.009222 | controller | skipping: Conditional result was False 2025-12-23 00:09:11.015353 | 2025-12-23 00:09:11.015417 | LOOP [bindep : Include package tasks] 2025-12-23 00:09:11.072024 | 2025-12-23 00:09:11.072159 | TASK [Run test-setup role] 2025-12-23 00:09:11.104328 | controller | ok 2025-12-23 00:09:11.128135 | 2025-12-23 00:09:11.128247 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-23 00:09:11.342856 | controller | ok 2025-12-23 00:09:11.354684 | 2025-12-23 00:09:11.354822 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-23 00:09:11.887992 | controller | skipping: Conditional result was False 2025-12-23 00:09:11.937553 | 2025-12-23 00:09:11.937738 | PLAY RECAP 2025-12-23 00:09:11.937820 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-23 00:09:11.937863 | 2025-12-23 00:09:12.078889 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-23 00:09:12.081080 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-23 00:09:12.745173 | 2025-12-23 00:09:12.745303 | PLAY [controller] 2025-12-23 00:09:12.765399 | 2025-12-23 00:09:12.765472 | TASK [Create the /root directory] 2025-12-23 00:09:13.121399 | controller | ok 2025-12-23 00:09:13.128000 | 2025-12-23 00:09:13.128076 | TASK [Install glibc-langpack-en] 2025-12-23 00:09:17.153461 | controller | ok: Nothing to do 2025-12-23 00:09:17.159465 | 2025-12-23 00:09:17.159530 | TASK [Ensure controller directory exists] 2025-12-23 00:09:17.378829 | controller | changed 2025-12-23 00:09:17.396367 | 2025-12-23 00:09:17.396518 | TASK [Install container runtime] 2025-12-23 00:09:17.456154 | controller | ok 2025-12-23 00:09:17.502134 | 2025-12-23 00:09:17.502250 | LOOP [ensure-podman : Find distribution installation] 2025-12-23 00:09:17.539717 | controller | ok: "/var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-23 00:09:17.558217 | controller | included: /var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-23 00:09:17.568757 | 2025-12-23 00:09:17.568866 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-23 00:10:24.836066 | controller | changed 2025-12-23 00:10:24.845621 | 2025-12-23 00:10:24.845753 | TASK [ensure-podman : Fetch podman version] 2025-12-23 00:10:25.526137 | controller | Client: Podman Engine 2025-12-23 00:10:25.526338 | controller | Version: 4.6.2 2025-12-23 00:10:25.526425 | controller | API Version: 4.6.2 2025-12-23 00:10:25.526519 | controller | Go Version: go1.19.12 2025-12-23 00:10:25.526628 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-23 00:10:25.526771 | controller | OS/Arch: linux/amd64 2025-12-23 00:10:25.891913 | controller | ok: Runtime: 0:00:00.337331 2025-12-23 00:10:25.905599 | 2025-12-23 00:10:25.905773 | TASK [ensure-podman : Print podman version installed] 2025-12-23 00:10:25.946767 | Podman version: Client: Podman Engine 2025-12-23 00:10:25.947022 | Version: 4.6.2 2025-12-23 00:10:25.947081 | API Version: 4.6.2 2025-12-23 00:10:25.947124 | Go Version: go1.19.12 2025-12-23 00:10:25.947165 | Built: Mon Aug 28 19:38:31 2023 2025-12-23 00:10:25.947209 | OS/Arch: linux/amd64 2025-12-23 00:10:25.961088 | 2025-12-23 00:10:25.961227 | TASK [ensure-podman : Validate podman engine] 2025-12-23 00:10:26.509746 | controller | skipping: Conditional result was False 2025-12-23 00:10:26.524524 | 2025-12-23 00:10:26.524722 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-23 00:10:26.554075 | controller | skipping: Conditional result was False 2025-12-23 00:10:26.587185 | 2025-12-23 00:10:26.587311 | TASK [Ensure python3.8 is present] 2025-12-23 00:10:26.611679 | controller | skipping: Conditional result was False 2025-12-23 00:10:26.617765 | 2025-12-23 00:10:26.617830 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-23 00:10:26.637256 | controller | ok 2025-12-23 00:10:26.657179 | 2025-12-23 00:10:26.657243 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-23 00:10:28.112291 | controller | ok: Nothing to do 2025-12-23 00:10:28.118058 | 2025-12-23 00:10:28.118125 | TASK [our-ensure-python : Also install python3-devel] 2025-12-23 00:10:37.962514 | controller | changed 2025-12-23 00:10:37.986938 | 2025-12-23 00:10:37.987083 | TASK [Run ensure-virtualenv role] 2025-12-23 00:10:38.017656 | controller | ok 2025-12-23 00:10:38.050773 | 2025-12-23 00:10:38.050872 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-23 00:10:38.304273 | controller | /usr/bin/virtualenv 2025-12-23 00:10:38.614776 | controller | ok: Runtime: 0:00:00.005189 2025-12-23 00:10:38.629744 | 2025-12-23 00:10:38.629892 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-23 00:10:38.664888 | controller | skipping: Conditional result was False 2025-12-23 00:10:38.665352 | controller | ok: All items complete 2025-12-23 00:10:38.665445 | 2025-12-23 00:10:38.694837 | 2025-12-23 00:10:38.695074 | TASK [Find the full path of the Python interpreter] 2025-12-23 00:10:38.939891 | controller | /usr/bin/python3 2025-12-23 00:10:39.245959 | controller | ok 2025-12-23 00:10:39.260053 | 2025-12-23 00:10:39.260202 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-23 00:10:40.120461 | controller | created virtual environment CPython3.11.0.final.0-64 in 468ms 2025-12-23 00:10:40.145495 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-23 00:10:40.145529 | 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-12-23 00:10:40.145538 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-23 00:10:40.145551 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-23 00:10:40.337324 | controller | changed 2025-12-23 00:10:40.350234 | 2025-12-23 00:10:40.350362 | TASK [Set selinux package] 2025-12-23 00:10:40.389066 | controller | ok 2025-12-23 00:10:40.400649 | 2025-12-23 00:10:40.400809 | TASK [Set selinux package (Fedora)] 2025-12-23 00:10:40.460179 | controller | ok 2025-12-23 00:10:40.472151 | 2025-12-23 00:10:40.472279 | TASK [Install selinux into virtualenv] 2025-12-23 00:11:06.074923 | controller | Collecting selinux-please-lie-to-me 2025-12-23 00:11:18.284249 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-23 00:11:18.623974 | controller | Collecting setuptools<50.0.0 2025-12-23 00:11:18.639857 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-23 00:11:18.683010 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 20.2 MB/s eta 0:00:00 2025-12-23 00:11:18.764282 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-23 00:11:18.764545 | controller | Attempting uninstall: setuptools 2025-12-23 00:11:18.766974 | controller | Found existing installation: setuptools 62.6.0 2025-12-23 00:11:18.845479 | controller | Uninstalling setuptools-62.6.0: 2025-12-23 00:11:18.856469 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-23 00:11:19.219184 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-23 00:11:30.649941 | controller | 2025-12-23 00:11:30.801138 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-23 00:11:30.801338 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-23 00:11:31.064519 | controller | ok: Runtime: 0:00:50.093317 2025-12-23 00:11:31.071004 | 2025-12-23 00:11:31.071089 | TASK [Install pytest-forked into virtualenv] 2025-12-23 00:11:54.867273 | controller | Collecting pytest-forked 2025-12-23 00:12:19.154819 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-23 00:12:19.200752 | controller | Collecting py 2025-12-23 00:12:19.208100 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-23 00:12:19.241854 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00 2025-12-23 00:12:19.348804 | controller | Collecting pytest>=3.10 2025-12-23 00:12:19.376154 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-23 00:12:19.398073 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 19.2 MB/s eta 0:00:00 2025-12-23 00:12:19.441571 | controller | Collecting iniconfig>=1.0.1 2025-12-23 00:12:19.467168 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-23 00:12:19.515786 | controller | Collecting packaging>=22 2025-12-23 00:12:19.538009 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-23 00:12:19.546138 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 12.3 MB/s eta 0:00:00 2025-12-23 00:12:19.580581 | controller | Collecting pluggy<2,>=1.5 2025-12-23 00:12:19.595987 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-23 00:12:19.658869 | controller | Collecting pygments>=2.7.2 2025-12-23 00:12:19.665569 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-23 00:12:19.702414 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 37.7 MB/s eta 0:00:00 2025-12-23 00:12:19.771405 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-23 00:12:20.885341 | 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 2025-12-23 00:12:20.895093 | controller | 2025-12-23 00:12:20.996508 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-23 00:12:20.996572 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-23 00:12:21.136709 | controller | ok: Runtime: 0:00:49.721149 2025-12-23 00:12:21.143076 | 2025-12-23 00:12:21.143146 | TASK [Update pip] 2025-12-23 00:12:21.700812 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-23 00:12:31.558272 | controller | Collecting pip 2025-12-23 00:12:43.755976 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-23 00:12:43.833222 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 25.6 MB/s eta 0:00:00 2025-12-23 00:12:43.902211 | controller | Installing collected packages: pip 2025-12-23 00:12:43.902434 | controller | Attempting uninstall: pip 2025-12-23 00:12:43.905568 | controller | Found existing installation: pip 22.2.2 2025-12-23 00:12:44.046876 | controller | Uninstalling pip-22.2.2: 2025-12-23 00:12:44.064958 | controller | Successfully uninstalled pip-22.2.2 2025-12-23 00:12:44.872385 | controller | Successfully installed pip-25.3 2025-12-23 00:12:45.214304 | controller | ok: Runtime: 0:00:23.565572 2025-12-23 00:12:45.222378 | 2025-12-23 00:12:45.222470 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-23 00:12:45.497207 | controller | changed 2025-12-23 00:12:45.513579 | 2025-12-23 00:12:45.513817 | TASK [Install ansible into virtualenv] 2025-12-23 00:12:46.051956 | controller | Processing ./src/github.com/ansible/ansible 2025-12-23 00:12:46.058410 | controller | Installing build dependencies: started 2025-12-23 00:13:32.580081 | controller | Installing build dependencies: finished with status 'done' 2025-12-23 00:13:33.348087 | controller | Getting requirements to build wheel: started 2025-12-23 00:13:33.348193 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-23 00:13:33.349076 | controller | Preparing metadata (pyproject.toml): started 2025-12-23 00:13:33.861913 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-23 00:13:33.867117 | 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-12-23 00:13:33.871159 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-23 00:13:34.085985 | controller | ERROR 2025-12-23 00:13:34.086206 | controller | { 2025-12-23 00:13:34.086296 | controller | "delta": "0:00:48.189224", 2025-12-23 00:13:34.086341 | controller | "end": "2025-12-23 00:13:33.942242", 2025-12-23 00:13:34.086380 | controller | "msg": "non-zero return code", 2025-12-23 00:13:34.086431 | controller | "rc": 1, 2025-12-23 00:13:34.086468 | controller | "start": "2025-12-23 00:12:45.753018" 2025-12-23 00:13:34.086504 | controller | } failure 2025-12-23 00:13:34.089033 | 2025-12-23 00:13:34.089127 | PLAY RECAP 2025-12-23 00:13:34.089207 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-23 00:13:34.089250 | 2025-12-23 00:13:34.215063 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-23 00:13:34.216064 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-23 00:13:34.767724 | 2025-12-23 00:13:34.767836 | PLAY [all] 2025-12-23 00:13:34.791350 | 2025-12-23 00:13:34.791459 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-23 00:13:35.075308 | controller | changed: non-zero return code 2025-12-23 00:13:35.089999 | 2025-12-23 00:13:35.090173 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-23 00:13:35.118205 | controller | skipping: Conditional result was False 2025-12-23 00:13:35.132556 | 2025-12-23 00:13:35.132755 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-23 00:13:35.170400 | 2025-12-23 00:13:35.170693 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-23 00:13:35.194303 | 2025-12-23 00:13:35.194460 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-23 00:13:35.209205 | controller | skipping: Conditional result was False 2025-12-23 00:13:35.219296 | 2025-12-23 00:13:35.219451 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-23 00:13:35.244084 | 2025-12-23 00:13:35.244254 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-23 00:13:35.259258 | controller | skipping: Conditional result was False 2025-12-23 00:13:35.268597 | 2025-12-23 00:13:35.268720 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-23 00:13:35.284234 | controller | skipping: Conditional result was False 2025-12-23 00:13:35.293455 | 2025-12-23 00:13:35.293546 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-23 00:13:35.308331 | controller | skipping: Conditional result was False 2025-12-23 00:13:35.345238 | 2025-12-23 00:13:35.345309 | PLAY RECAP 2025-12-23 00:13:35.345356 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-23 00:13:35.345381 | 2025-12-23 00:13:35.441542 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-23 00:13:35.442445 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-23 00:13:35.999583 | 2025-12-23 00:13:35.999736 | PLAY [all:!appliance*] 2025-12-23 00:13:36.021913 | 2025-12-23 00:13:36.022001 | TASK [unregister the node] 2025-12-23 00:13:36.558400 | controller | skipping: Conditional result was False 2025-12-23 00:13:36.571510 | 2025-12-23 00:13:36.571709 | TASK [include_role : fetch-output] 2025-12-23 00:13:36.620865 | controller | ok 2025-12-23 00:13:36.656764 | 2025-12-23 00:13:36.656917 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-23 00:13:36.733515 | controller | skipping: Conditional result was False 2025-12-23 00:13:36.747898 | 2025-12-23 00:13:36.748100 | TASK [fetch-output : Set log path for single node] 2025-12-23 00:13:36.797997 | controller | ok 2025-12-23 00:13:36.811327 | 2025-12-23 00:13:36.811490 | LOOP [fetch-output : Ensure local output dirs] 2025-12-23 00:13:37.236433 | controller -> localhost | ok: "/var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/logs" 2025-12-23 00:13:37.495695 | controller -> localhost | changed: "/var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/artifacts" 2025-12-23 00:13:37.717536 | controller -> localhost | changed: "/var/lib/zuul/builds/2dc18e1c3b254f449bb2a3c94973a002/work/docs" 2025-12-23 00:13:37.732821 | 2025-12-23 00:13:37.732903 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-23 00:13:38.436719 | controller | changed: 2025-12-23 00:13:38.437242 | controller | .d..t...... ./ 2025-12-23 00:13:38.437323 | controller | cd+++++++++ controller/ 2025-12-23 00:13:38.437430 | controller | changed: All items complete 2025-12-23 00:13:38.437500 | 2025-12-23 00:13:38.943139 | controller | changed: .d..t...... ./ 2025-12-23 00:13:39.489383 | controller | changed: .d..t...... ./ 2025-12-23 00:13:39.525883 | 2025-12-23 00:13:39.526076 | TASK [include_role : fetch-output-openshift] 2025-12-23 00:13:39.553209 | controller | skipping: Conditional result was False 2025-12-23 00:13:39.568867 | 2025-12-23 00:13:39.569017 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-23 00:13:39.623694 | controller | skipping: Conditional result was False 2025-12-23 00:13:39.644772 | controller | skipping: Conditional result was False 2025-12-23 00:13:39.705231 | 2025-12-23 00:13:39.705364 | PLAY [localhost] 2025-12-23 00:13:39.721768 | 2025-12-23 00:13:39.721848 | TASK [Run Zuul manifest role] 2025-12-23 00:13:39.751511 | localhost | ok 2025-12-23 00:13:39.770233 | 2025-12-23 00:13:39.770324 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-23 00:13:40.236518 | localhost | changed 2025-12-23 00:13:40.246518 | 2025-12-23 00:13:40.246656 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-23 00:13:40.284864 | localhost | ok 2025-12-23 00:13:40.304954 | 2025-12-23 00:13:40.305124 | TASK [Set zuul-log-path fact] 2025-12-23 00:13:40.327090 | localhost | ok 2025-12-23 00:13:40.347460 | 2025-12-23 00:13:40.347606 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-23 00:13:40.379804 | localhost | ok 2025-12-23 00:13:40.391722 | 2025-12-23 00:13:40.391829 | LOOP [Run upload-logs-swift role] 2025-12-23 00:13:40.440193 | localhost | Output suppressed because no_log was given 2025-12-23 00:13:40.495495 | 2025-12-23 00:13:40.495601 | TASK [Set zuul-log-path fact] 2025-12-23 00:13:40.530887 | localhost | skipping: Conditional result was False 2025-12-23 00:13:40.538365 | 2025-12-23 00:13:40.538471 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-23 00:13:40.973212 | localhost -> localhost | ok: Runtime: 0:00:00.007422 2025-12-23 00:13:41.025752 | 2025-12-23 00:13:41.025895 | TASK [upload-logs-swift : Upload logs to swift]