2025-11-09 00:14:43.594086 | Job console starting... 2025-11-09 00:14:43.606192 | Updating repositories 2025-11-09 00:14:43.707610 | Preparing job workspace 2025-11-09 00:14:47.580097 | Running Ansible setup... 2025-11-09 00:14:55.583536 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-09 00:14:56.219369 | 2025-11-09 00:14:56.219500 | PLAY [localhost] 2025-11-09 00:14:56.229353 | 2025-11-09 00:14:56.229437 | TASK [Gathering Facts] 2025-11-09 00:14:57.242172 | localhost | ok 2025-11-09 00:14:57.283566 | 2025-11-09 00:14:57.283814 | TASK [Setup log path fact] 2025-11-09 00:14:57.315455 | localhost | ok 2025-11-09 00:14:57.338118 | 2025-11-09 00:14:57.338310 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-09 00:14:57.382494 | localhost | ok 2025-11-09 00:14:57.397029 | 2025-11-09 00:14:57.397178 | TASK [emit-job-header : Print job information] 2025-11-09 00:14:57.448957 | # Job Information 2025-11-09 00:14:57.449126 | Ansible Version: 2.15.12 2025-11-09 00:14:57.449159 | Job: ansible-test-sanity-docker-milestone 2025-11-09 00:14:57.449181 | Pipeline: periodic 2025-11-09 00:14:57.449199 | Executor: ze02.softwarefactory-project.io 2025-11-09 00:14:57.449217 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-09 00:14:57.449237 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/3b1/ansible/3b13349c66f24961bf51dc52e895b11c/ 2025-11-09 00:14:57.449256 | Event ID: 280be395c61a4a10afa9abd9d444e89a 2025-11-09 00:14:57.454243 | 2025-11-09 00:14:57.454363 | LOOP [emit-job-header : Print node information] 2025-11-09 00:14:57.570586 | localhost | ok: 2025-11-09 00:14:57.570843 | localhost | # Node Information 2025-11-09 00:14:57.570883 | localhost | Inventory Hostname: controller 2025-11-09 00:14:57.570909 | localhost | Hostname: np0005515822 2025-11-09 00:14:57.570934 | localhost | Username: zuul 2025-11-09 00:14:57.570959 | localhost | Distro: Fedora 37 2025-11-09 00:14:57.570982 | localhost | Provider: ansible-vexxhost-ams1 2025-11-09 00:14:57.571004 | localhost | Region: ams1 2025-11-09 00:14:57.571025 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-09 00:14:57.571113 | localhost | Product Name: OpenStack Nova 2025-11-09 00:14:57.571145 | localhost | Interface IP: 38.129.16.128 2025-11-09 00:14:57.579778 | 2025-11-09 00:14:57.579902 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-09 00:14:57.949619 | localhost -> localhost | changed 2025-11-09 00:14:57.955931 | 2025-11-09 00:14:57.956006 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-09 00:14:58.866907 | localhost -> localhost | changed 2025-11-09 00:14:58.892293 | 2025-11-09 00:14:58.892421 | PLAY [all:!appliance*] 2025-11-09 00:14:58.917254 | 2025-11-09 00:14:58.917324 | TASK [include_role : start-zuul-console] 2025-11-09 00:14:58.938353 | controller | ok 2025-11-09 00:14:58.962061 | 2025-11-09 00:14:58.962208 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-09 00:15:00.038950 | controller | ok 2025-11-09 00:15:00.068470 | 2025-11-09 00:15:00.068617 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-09 00:15:02.557091 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-09 00:15:02.572082 | 2025-11-09 00:15:02.572217 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-09 00:15:02.945110 | controller | skipping: Conditional result was False 2025-11-09 00:15:02.959118 | 2025-11-09 00:15:02.959296 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-09 00:15:02.986484 | controller | skipping: Conditional result was False 2025-11-09 00:15:03.000275 | 2025-11-09 00:15:03.000411 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-09 00:15:03.028466 | controller | skipping: Conditional result was False 2025-11-09 00:15:03.043427 | 2025-11-09 00:15:03.043715 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-09 00:15:03.073003 | controller | skipping: Conditional result was False 2025-11-09 00:15:03.087246 | 2025-11-09 00:15:03.087407 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-09 00:15:03.116440 | controller | skipping: Conditional result was False 2025-11-09 00:15:03.128152 | 2025-11-09 00:15:03.128270 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-09 00:15:03.164735 | controller | skipping: Conditional result was False 2025-11-09 00:15:03.191002 | 2025-11-09 00:15:03.191201 | TASK [Disable Fedora Modular] 2025-11-09 00:15:04.342138 | controller | changed 2025-11-09 00:15:04.359035 | 2025-11-09 00:15:04.359279 | TASK [Enable EPEL] 2025-11-09 00:15:04.388418 | controller | skipping: Conditional result was False 2025-11-09 00:15:04.403998 | 2025-11-09 00:15:04.404206 | TASK [Register the RHEL node] 2025-11-09 00:15:04.830315 | 2025-11-09 00:15:04.830555 | TASK [Show the subscription-manager status] 2025-11-09 00:15:05.203179 | controller | skipping: Conditional result was False 2025-11-09 00:15:05.218120 | 2025-11-09 00:15:05.218280 | TASK [Enable EPEL on RHEL] 2025-11-09 00:15:05.617114 | controller | skipping: Conditional result was False 2025-11-09 00:15:05.632387 | 2025-11-09 00:15:05.632595 | TASK [Install git and tox] 2025-11-09 00:17:21.570976 | controller | changed 2025-11-09 00:17:21.577938 | 2025-11-09 00:17:21.578053 | TASK [include_role : prepare-workspace] 2025-11-09 00:17:21.609886 | controller | ok 2025-11-09 00:17:21.630972 | 2025-11-09 00:17:21.631063 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-09 00:17:22.476824 | controller | ok 2025-11-09 00:17:22.490378 | 2025-11-09 00:17:22.490532 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-09 00:17:38.312349 | controller | Output suppressed because no_log was given 2025-11-09 00:17:38.334501 | 2025-11-09 00:17:38.334650 | TASK [include_role : prepare-workspace-openshift] 2025-11-09 00:17:38.377939 | controller | skipping: Conditional result was False 2025-11-09 00:17:38.464960 | 2025-11-09 00:17:38.465103 | PLAY [all:!appliance] 2025-11-09 00:17:38.481805 | 2025-11-09 00:17:38.481917 | TASK [Run add-build-sshkey role (RSA)] 2025-11-09 00:17:38.529207 | controller | ok 2025-11-09 00:17:38.556086 | 2025-11-09 00:17:38.556258 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-09 00:17:38.831190 | controller -> localhost | ok 2025-11-09 00:17:38.848799 | 2025-11-09 00:17:38.849035 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-09 00:17:38.882348 | controller | ok 2025-11-09 00:17:38.908751 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-09 00:17:38.919759 | 2025-11-09 00:17:38.919863 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-09 00:17:39.518891 | controller -> localhost | Generating public/private rsa key pair. 2025-11-09 00:17:39.519382 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_rsa. 2025-11-09 00:17:39.519412 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_rsa.pub. 2025-11-09 00:17:39.519435 | controller -> localhost | The key fingerprint is: 2025-11-09 00:17:39.519458 | controller -> localhost | SHA256:fPhzjy5iPqhBznXqHW5dxgFr0L7XQbIc4PgKJWvJRNc zuul-build-sshkey 2025-11-09 00:17:39.519478 | controller -> localhost | The key's randomart image is: 2025-11-09 00:17:39.519497 | controller -> localhost | +---[RSA 2048]----+ 2025-11-09 00:17:39.519515 | controller -> localhost | | . .o.. | 2025-11-09 00:17:39.519535 | controller -> localhost | | . ..oE o . | 2025-11-09 00:17:39.519552 | controller -> localhost | | o oo.+ = | 2025-11-09 00:17:39.519570 | controller -> localhost | | o * o+ + . | 2025-11-09 00:17:39.519587 | controller -> localhost | | . B S.oo o . | 2025-11-09 00:17:39.519622 | controller -> localhost | | + o + +. = . | 2025-11-09 00:17:39.519644 | controller -> localhost | | + ..o.o+. | 2025-11-09 00:17:39.519678 | controller -> localhost | | o.o=.oo o | 2025-11-09 00:17:39.519703 | controller -> localhost | | ...++o oo . | 2025-11-09 00:17:39.519725 | controller -> localhost | +----[SHA256]-----+ 2025-11-09 00:17:39.519785 | controller -> localhost | ok: Runtime: 0:00:00.138835 2025-11-09 00:17:39.528781 | 2025-11-09 00:17:39.528857 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-09 00:17:39.574128 | controller | ok 2025-11-09 00:17:39.585128 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-09 00:17:39.594193 | 2025-11-09 00:17:39.594284 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-09 00:17:39.620226 | controller | skipping: Conditional result was False 2025-11-09 00:17:39.629459 | 2025-11-09 00:17:39.629602 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-09 00:17:40.759211 | controller | changed 2025-11-09 00:17:40.776001 | 2025-11-09 00:17:40.776194 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-09 00:17:41.462060 | controller | ok 2025-11-09 00:17:41.473393 | 2025-11-09 00:17:41.473572 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-09 00:17:44.711643 | controller | changed 2025-11-09 00:17:44.726225 | 2025-11-09 00:17:44.726621 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-09 00:17:47.936784 | controller | changed 2025-11-09 00:17:47.953054 | 2025-11-09 00:17:47.953244 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-09 00:17:47.982818 | controller | skipping: Conditional result was False 2025-11-09 00:17:48.000868 | 2025-11-09 00:17:48.001151 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-09 00:17:48.531337 | controller -> localhost | changed 2025-11-09 00:17:48.563249 | 2025-11-09 00:17:48.563514 | TASK [add-build-sshkey : Add back temp key] 2025-11-09 00:17:48.919952 | controller -> localhost | Identity added: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_rsa (zuul-build-sshkey) 2025-11-09 00:17:48.920259 | controller -> localhost | ok: Runtime: 0:00:00.012402 2025-11-09 00:17:48.927200 | 2025-11-09 00:17:48.927263 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-09 00:17:49.988187 | controller | ok 2025-11-09 00:17:50.001453 | 2025-11-09 00:17:50.001738 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-09 00:17:50.034485 | controller | skipping: Conditional result was False 2025-11-09 00:17:50.061475 | 2025-11-09 00:17:50.061865 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-09 00:17:50.093950 | controller | ok 2025-11-09 00:17:50.121516 | 2025-11-09 00:17:50.121642 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-09 00:17:50.382154 | controller -> localhost | ok 2025-11-09 00:17:50.396536 | 2025-11-09 00:17:50.396731 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-09 00:17:50.444563 | controller | ok 2025-11-09 00:17:50.463904 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-09 00:17:50.473529 | 2025-11-09 00:17:50.473636 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-09 00:17:50.796507 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-09 00:17:50.796897 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_ecdsa. 2025-11-09 00:17:50.796986 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_ecdsa.pub. 2025-11-09 00:17:50.797053 | controller -> localhost | The key fingerprint is: 2025-11-09 00:17:50.797098 | controller -> localhost | SHA256:g5PCApwvwGmk8wsGKRpY3UyNpO6WCnUYQhx0uymt5XY zuul-build-sshkey 2025-11-09 00:17:50.797140 | controller -> localhost | The key's randomart image is: 2025-11-09 00:17:50.797180 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-09 00:17:50.797220 | controller -> localhost | |o=oo =oo | 2025-11-09 00:17:50.797259 | controller -> localhost | |B++ o.+ . | 2025-11-09 00:17:50.797299 | controller -> localhost | |%*... | 2025-11-09 00:17:50.797339 | controller -> localhost | |**o=o o | 2025-11-09 00:17:50.797377 | controller -> localhost | |o+=*= + S | 2025-11-09 00:17:50.797415 | controller -> localhost | |.o*= o . . | 2025-11-09 00:17:50.797452 | controller -> localhost | |...o+E | 2025-11-09 00:17:50.797490 | controller -> localhost | | ..o. | 2025-11-09 00:17:50.797527 | controller -> localhost | | . | 2025-11-09 00:17:50.797566 | controller -> localhost | +----[SHA256]-----+ 2025-11-09 00:17:50.797711 | controller -> localhost | ok: Runtime: 0:00:00.015026 2025-11-09 00:17:50.813634 | 2025-11-09 00:17:50.813804 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-09 00:17:50.856831 | controller | ok 2025-11-09 00:17:50.877849 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-09 00:17:50.894039 | 2025-11-09 00:17:50.894208 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-09 00:17:50.922255 | controller | skipping: Conditional result was False 2025-11-09 00:17:50.937520 | 2025-11-09 00:17:50.937628 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-09 00:17:51.948816 | controller | changed 2025-11-09 00:17:51.955939 | 2025-11-09 00:17:51.956026 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-09 00:17:52.660368 | controller | ok 2025-11-09 00:17:52.673289 | 2025-11-09 00:17:52.673443 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-09 00:17:55.831452 | controller | changed 2025-11-09 00:17:55.844918 | 2025-11-09 00:17:55.845270 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-09 00:17:59.117220 | controller | changed 2025-11-09 00:17:59.131715 | 2025-11-09 00:17:59.131950 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-09 00:17:59.170991 | controller | skipping: Conditional result was False 2025-11-09 00:17:59.187545 | 2025-11-09 00:17:59.188011 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-09 00:17:59.454200 | controller -> localhost | changed 2025-11-09 00:17:59.474567 | 2025-11-09 00:17:59.474842 | TASK [add-build-sshkey : Add back temp key] 2025-11-09 00:17:59.830042 | controller -> localhost | Identity added: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/3b13349c66f24961bf51dc52e895b11c_id_ecdsa (zuul-build-sshkey) 2025-11-09 00:17:59.830345 | controller -> localhost | ok: Runtime: 0:00:00.011390 2025-11-09 00:17:59.842699 | 2025-11-09 00:17:59.842792 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-09 00:18:00.626716 | controller | ok 2025-11-09 00:18:00.646018 | 2025-11-09 00:18:00.646256 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-09 00:18:00.688622 | controller | skipping: Conditional result was False 2025-11-09 00:18:00.716594 | 2025-11-09 00:18:00.716851 | TASK [include_role : remove-zuul-sshkey] 2025-11-09 00:18:00.745120 | controller | skipping: Conditional result was False 2025-11-09 00:18:00.754999 | 2025-11-09 00:18:00.755101 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-09 00:18:01.483125 | controller | ok: "logs" 2025-11-09 00:18:01.483793 | controller | ok: All items complete 2025-11-09 00:18:01.483872 | 2025-11-09 00:18:02.182341 | controller | ok: "artifacts" 2025-11-09 00:18:02.896936 | controller | ok: "docs" 2025-11-09 00:18:02.917938 | 2025-11-09 00:18:02.918137 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-09 00:18:03.663084 | controller | changed: "logs" 2025-11-09 00:18:04.380581 | controller | changed: "artifacts" 2025-11-09 00:18:05.061315 | controller | changed: "docs" 2025-11-09 00:18:05.098193 | 2025-11-09 00:18:05.098320 | PLAY RECAP 2025-11-09 00:18:05.098367 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-09 00:18:05.098393 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-09 00:18:05.098410 | 2025-11-09 00:18:05.249632 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-09 00:18:05.250836 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-09 00:18:05.952122 | 2025-11-09 00:18:05.952269 | PLAY [all] 2025-11-09 00:18:05.976419 | 2025-11-09 00:18:05.976569 | TASK [Install binary dependencies] 2025-11-09 00:18:06.049993 | controller | ok 2025-11-09 00:18:06.070449 | 2025-11-09 00:18:06.070621 | TASK [bindep : Include find tasks] 2025-11-09 00:18:06.111307 | controller | ok 2025-11-09 00:18:06.119429 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-09 00:18:06.125901 | 2025-11-09 00:18:06.125970 | TASK [bindep : Look for bindep.txt] 2025-11-09 00:18:07.241170 | controller | ok 2025-11-09 00:18:07.256496 | 2025-11-09 00:18:07.256816 | TASK [bindep : Define bindep_file fact] 2025-11-09 00:18:07.287619 | controller | skipping: Conditional result was False 2025-11-09 00:18:07.298418 | 2025-11-09 00:18:07.298563 | TASK [bindep : Look for other-requirements.txt] 2025-11-09 00:18:08.044011 | controller | ok 2025-11-09 00:18:08.057709 | 2025-11-09 00:18:08.057938 | TASK [bindep : Define bindep_file fact] 2025-11-09 00:18:08.096272 | controller | skipping: Conditional result was False 2025-11-09 00:18:08.109560 | 2025-11-09 00:18:08.109876 | TASK [bindep : Look for bindep fallback file] 2025-11-09 00:18:08.148508 | controller | skipping: Conditional result was False 2025-11-09 00:18:08.160921 | 2025-11-09 00:18:08.161171 | TASK [bindep : Define bindep_file fact] 2025-11-09 00:18:08.188921 | controller | skipping: Conditional result was False 2025-11-09 00:18:08.203300 | 2025-11-09 00:18:08.203535 | TASK [bindep : Include bindep tasks] 2025-11-09 00:18:08.231461 | controller | skipping: Conditional result was False 2025-11-09 00:18:08.241983 | 2025-11-09 00:18:08.242149 | TASK [bindep : Include install tasks] 2025-11-09 00:18:08.268266 | controller | skipping: Conditional result was False 2025-11-09 00:18:08.277416 | 2025-11-09 00:18:08.277548 | LOOP [bindep : Include package tasks] 2025-11-09 00:18:08.349084 | 2025-11-09 00:18:08.349337 | TASK [Run test-setup role] 2025-11-09 00:18:08.370396 | controller | ok 2025-11-09 00:18:08.387843 | 2025-11-09 00:18:08.387908 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-09 00:18:09.162130 | controller | ok 2025-11-09 00:18:09.170559 | 2025-11-09 00:18:09.170756 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-09 00:18:09.552183 | controller | skipping: Conditional result was False 2025-11-09 00:18:09.590154 | 2025-11-09 00:18:09.590324 | PLAY RECAP 2025-11-09 00:18:09.590386 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-09 00:18:09.590416 | 2025-11-09 00:18:09.746141 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-09 00:18:09.747100 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-09 00:18:10.387881 | 2025-11-09 00:18:10.388134 | PLAY [controller] 2025-11-09 00:18:10.408903 | 2025-11-09 00:18:10.409043 | TASK [Create the /root directory] 2025-11-09 00:18:11.530583 | controller | ok 2025-11-09 00:18:11.539705 | 2025-11-09 00:18:11.539825 | TASK [Install glibc-langpack-en] 2025-11-09 00:18:20.012193 | controller | ok: Nothing to do 2025-11-09 00:18:20.020598 | 2025-11-09 00:18:20.020860 | TASK [Ensure controller directory exists] 2025-11-09 00:18:20.858306 | controller | changed 2025-11-09 00:18:20.892619 | 2025-11-09 00:18:20.892834 | TASK [Install container runtime] 2025-11-09 00:18:20.948972 | controller | ok 2025-11-09 00:18:21.001337 | 2025-11-09 00:18:21.001477 | LOOP [ensure-podman : Find distribution installation] 2025-11-09 00:18:21.038988 | controller | ok: "/var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-11-09 00:18:21.054986 | controller | included: /var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-11-09 00:18:21.062166 | 2025-11-09 00:18:21.062254 | TASK [ensure-podman : Install podman (RedHat)] 2025-11-09 00:20:24.259363 | controller | changed 2025-11-09 00:20:24.276106 | 2025-11-09 00:20:24.276343 | TASK [ensure-podman : Fetch podman version] 2025-11-09 00:20:25.489781 | controller | Client: Podman Engine 2025-11-09 00:20:25.525143 | controller | Version: 4.6.2 2025-11-09 00:20:25.525201 | controller | API Version: 4.6.2 2025-11-09 00:20:25.525210 | controller | Go Version: go1.19.12 2025-11-09 00:20:25.525230 | controller | Built: Mon Aug 28 19:38:31 2023 2025-11-09 00:20:25.525238 | controller | OS/Arch: linux/amd64 2025-11-09 00:20:25.658245 | controller | ok: Runtime: 0:00:00.302384 2025-11-09 00:20:25.666739 | 2025-11-09 00:20:25.666837 | TASK [ensure-podman : Print podman version installed] 2025-11-09 00:20:25.710160 | Podman version: Client: Podman Engine 2025-11-09 00:20:25.710468 | Version: 4.6.2 2025-11-09 00:20:25.710510 | API Version: 4.6.2 2025-11-09 00:20:25.710538 | Go Version: go1.19.12 2025-11-09 00:20:25.710564 | Built: Mon Aug 28 19:38:31 2023 2025-11-09 00:20:25.710589 | OS/Arch: linux/amd64 2025-11-09 00:20:25.718247 | 2025-11-09 00:20:25.718333 | TASK [ensure-podman : Validate podman engine] 2025-11-09 00:20:26.076214 | controller | skipping: Conditional result was False 2025-11-09 00:20:26.090561 | 2025-11-09 00:20:26.090738 | TASK [ensure-podman : Set up docker compatability socket] 2025-11-09 00:20:26.118111 | controller | skipping: Conditional result was False 2025-11-09 00:20:26.142723 | 2025-11-09 00:20:26.142864 | TASK [Ensure python3.8 is present] 2025-11-09 00:20:26.169791 | controller | skipping: Conditional result was False 2025-11-09 00:20:26.183555 | 2025-11-09 00:20:26.183749 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-09 00:20:26.213268 | controller | ok 2025-11-09 00:20:26.245525 | 2025-11-09 00:20:26.245643 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-09 00:20:29.729103 | controller | ok: Nothing to do 2025-11-09 00:20:29.743830 | 2025-11-09 00:20:29.743970 | TASK [our-ensure-python : Also install python3-devel] 2025-11-09 00:20:44.057170 | controller | changed 2025-11-09 00:20:44.082490 | 2025-11-09 00:20:44.082640 | TASK [Run ensure-virtualenv role] 2025-11-09 00:20:44.108555 | controller | ok 2025-11-09 00:20:44.139007 | 2025-11-09 00:20:44.139119 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-09 00:20:44.984754 | controller | /usr/bin/virtualenv 2025-11-09 00:20:45.499793 | controller | ok: Runtime: 0:00:00.008580 2025-11-09 00:20:45.513457 | 2025-11-09 00:20:45.513619 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-09 00:20:45.547012 | controller | skipping: Conditional result was False 2025-11-09 00:20:45.547373 | controller | ok: All items complete 2025-11-09 00:20:45.547399 | 2025-11-09 00:20:45.578506 | 2025-11-09 00:20:45.578821 | TASK [Find the full path of the Python interpreter] 2025-11-09 00:20:46.408082 | controller | /usr/bin/python3 2025-11-09 00:20:46.995063 | controller | ok 2025-11-09 00:20:47.004760 | 2025-11-09 00:20:47.004998 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-09 00:20:48.890926 | controller | created virtual environment CPython3.11.0.final.0-64 in 845ms 2025-11-09 00:20:48.960288 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-09 00:20:48.960972 | 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-09 00:20:48.961272 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-09 00:20:48.961577 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-09 00:20:49.383787 | controller | changed 2025-11-09 00:20:49.395345 | 2025-11-09 00:20:49.395978 | TASK [Set selinux package] 2025-11-09 00:20:49.440781 | controller | ok 2025-11-09 00:20:49.458697 | 2025-11-09 00:20:49.458971 | TASK [Set selinux package (Fedora)] 2025-11-09 00:20:49.514698 | controller | ok 2025-11-09 00:20:49.523257 | 2025-11-09 00:20:49.523350 | TASK [Install selinux into virtualenv] 2025-11-09 00:20:52.578624 | controller | Collecting selinux-please-lie-to-me 2025-11-09 00:20:52.652519 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-09 00:20:53.170903 | controller | Collecting setuptools<50.0.0 2025-11-09 00:20:53.207203 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-09 00:20:53.259752 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 16.8 MB/s eta 0:00:00 2025-11-09 00:20:53.400293 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-09 00:20:53.400638 | controller | Attempting uninstall: setuptools 2025-11-09 00:20:53.405465 | controller | Found existing installation: setuptools 62.6.0 2025-11-09 00:20:53.511422 | controller | Uninstalling setuptools-62.6.0: 2025-11-09 00:20:53.528233 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-09 00:20:54.235661 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-09 00:20:54.448703 | controller | 2025-11-09 00:20:54.723707 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-09 00:20:54.723760 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-09 00:20:54.900272 | controller | ok: Runtime: 0:00:04.388048 2025-11-09 00:20:54.914501 | 2025-11-09 00:20:54.914659 | TASK [Install pytest-forked into virtualenv] 2025-11-09 00:20:56.413694 | controller | Collecting pytest-forked 2025-11-09 00:20:56.475075 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-09 00:20:56.532278 | controller | Collecting py 2025-11-09 00:20:56.538792 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-09 00:20:56.573629 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.9 MB/s eta 0:00:00 2025-11-09 00:20:56.752351 | controller | Collecting pytest>=3.10 2025-11-09 00:20:56.758138 | controller | Downloading pytest-9.0.0-py3-none-any.whl (373 kB) 2025-11-09 00:20:56.776972 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.4/373.4 kB 24.2 MB/s eta 0:00:00 2025-11-09 00:20:56.828345 | controller | Collecting iniconfig>=1.0.1 2025-11-09 00:20:56.832943 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-11-09 00:20:56.904092 | controller | Collecting packaging>=22 2025-11-09 00:20:56.908118 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-09 00:20:56.921370 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 5.8 MB/s eta 0:00:00 2025-11-09 00:20:56.967949 | controller | Collecting pluggy<2,>=1.5 2025-11-09 00:20:56.974044 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-09 00:20:57.058421 | controller | Collecting pygments>=2.7.2 2025-11-09 00:20:57.067261 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-09 00:20:57.102090 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 38.7 MB/s eta 0:00:00 2025-11-09 00:20:57.222013 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-11-09 00:20:59.793650 | 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.0 pytest-forked-1.6.0 2025-11-09 00:20:59.808501 | controller | 2025-11-09 00:21:00.045719 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-09 00:21:00.045792 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-11-09 00:21:00.310953 | controller | ok: Runtime: 0:00:04.342632 2025-11-09 00:21:00.325575 | 2025-11-09 00:21:00.325803 | TASK [Update pip] 2025-11-09 00:21:01.689639 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-11-09 00:21:01.976609 | controller | Collecting pip 2025-11-09 00:21:02.046891 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-09 00:21:02.143924 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 19.3 MB/s eta 0:00:00 2025-11-09 00:21:02.277771 | controller | Installing collected packages: pip 2025-11-09 00:21:02.278160 | controller | Attempting uninstall: pip 2025-11-09 00:21:02.282494 | controller | Found existing installation: pip 22.2.2 2025-11-09 00:21:02.553187 | controller | Uninstalling pip-22.2.2: 2025-11-09 00:21:02.588236 | controller | Successfully uninstalled pip-22.2.2 2025-11-09 00:21:04.617206 | controller | Successfully installed pip-25.3 2025-11-09 00:21:05.212772 | controller | ok: Runtime: 0:00:03.819617 2025-11-09 00:21:05.227809 | 2025-11-09 00:21:05.228167 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-11-09 00:21:06.159909 | controller | changed 2025-11-09 00:21:06.171951 | 2025-11-09 00:21:06.172101 | TASK [Install ansible into virtualenv] 2025-11-09 00:21:07.494668 | controller | Processing ./src/github.com/ansible/ansible 2025-11-09 00:21:07.503327 | controller | Installing build dependencies: started 2025-11-09 00:21:09.477861 | controller | Installing build dependencies: finished with status 'done' 2025-11-09 00:21:09.479227 | controller | Getting requirements to build wheel: started 2025-11-09 00:21:11.001513 | controller | Getting requirements to build wheel: finished with status 'done' 2025-11-09 00:21:11.909335 | controller | Preparing metadata (pyproject.toml): started 2025-11-09 00:21:11.909388 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-11-09 00:21:11.914459 | 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-09 00:21:11.926583 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-11-09 00:21:12.567212 | controller | ERROR 2025-11-09 00:21:12.567548 | controller | { 2025-11-09 00:21:12.567629 | controller | "delta": "0:00:05.240379", 2025-11-09 00:21:12.567716 | controller | "end": "2025-11-09 00:21:12.105872", 2025-11-09 00:21:12.567759 | controller | "msg": "non-zero return code", 2025-11-09 00:21:12.567812 | controller | "rc": 1, 2025-11-09 00:21:12.567849 | controller | "start": "2025-11-09 00:21:06.865493" 2025-11-09 00:21:12.567884 | controller | } failure 2025-11-09 00:21:12.571841 | 2025-11-09 00:21:12.571943 | PLAY RECAP 2025-11-09 00:21:12.572028 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-11-09 00:21:12.572073 | 2025-11-09 00:21:12.733283 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-09 00:21:12.737162 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-09 00:21:13.464117 | 2025-11-09 00:21:13.464302 | PLAY [all] 2025-11-09 00:21:13.487746 | 2025-11-09 00:21:13.487893 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-09 00:21:15.360013 | controller | changed: non-zero return code 2025-11-09 00:21:15.374184 | 2025-11-09 00:21:15.374372 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-09 00:21:15.403494 | controller | skipping: Conditional result was False 2025-11-09 00:21:15.416553 | 2025-11-09 00:21:15.416741 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-09 00:21:15.471044 | 2025-11-09 00:21:15.471316 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-09 00:21:15.522447 | 2025-11-09 00:21:15.522757 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-09 00:21:15.550451 | controller | skipping: Conditional result was False 2025-11-09 00:21:15.567519 | 2025-11-09 00:21:15.567725 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-09 00:21:15.618327 | 2025-11-09 00:21:15.618606 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-09 00:21:15.646245 | controller | skipping: Conditional result was False 2025-11-09 00:21:15.655188 | 2025-11-09 00:21:15.655282 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-09 00:21:15.681106 | controller | skipping: Conditional result was False 2025-11-09 00:21:15.694209 | 2025-11-09 00:21:15.694352 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-09 00:21:15.721964 | controller | skipping: Conditional result was False 2025-11-09 00:21:15.779587 | 2025-11-09 00:21:15.779907 | PLAY RECAP 2025-11-09 00:21:15.779985 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-09 00:21:15.780015 | 2025-11-09 00:21:15.908746 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-09 00:21:15.910595 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-09 00:21:16.590845 | 2025-11-09 00:21:16.591002 | PLAY [all:!appliance*] 2025-11-09 00:21:16.613295 | 2025-11-09 00:21:16.613459 | TASK [unregister the node] 2025-11-09 00:21:16.965865 | controller | skipping: Conditional result was False 2025-11-09 00:21:16.972452 | 2025-11-09 00:21:16.972542 | TASK [include_role : fetch-output] 2025-11-09 00:21:17.003580 | controller | ok 2025-11-09 00:21:17.024046 | 2025-11-09 00:21:17.024209 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-09 00:21:17.069754 | controller | skipping: Conditional result was False 2025-11-09 00:21:17.084917 | 2025-11-09 00:21:17.085099 | TASK [fetch-output : Set log path for single node] 2025-11-09 00:21:17.138374 | controller | ok 2025-11-09 00:21:17.155423 | 2025-11-09 00:21:17.155713 | LOOP [fetch-output : Ensure local output dirs] 2025-11-09 00:21:17.619307 | controller -> localhost | ok: "/var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/logs" 2025-11-09 00:21:17.976217 | controller -> localhost | changed: "/var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/artifacts" 2025-11-09 00:21:18.255022 | controller -> localhost | changed: "/var/lib/zuul/builds/3b13349c66f24961bf51dc52e895b11c/work/docs" 2025-11-09 00:21:18.278909 | 2025-11-09 00:21:18.279093 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-09 00:21:20.597247 | controller | changed: 2025-11-09 00:21:20.597892 | controller | .d..t...... ./ 2025-11-09 00:21:20.597977 | controller | cd+++++++++ controller/ 2025-11-09 00:21:20.598062 | controller | changed: All items complete 2025-11-09 00:21:20.598117 | 2025-11-09 00:21:22.746086 | controller | changed: .d..t...... ./ 2025-11-09 00:21:24.837374 | controller | changed: .d..t...... ./ 2025-11-09 00:21:24.870263 | 2025-11-09 00:21:24.870520 | TASK [include_role : fetch-output-openshift] 2025-11-09 00:21:24.897278 | controller | skipping: Conditional result was False 2025-11-09 00:21:24.910065 | 2025-11-09 00:21:24.910240 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-09 00:21:24.957185 | controller | skipping: Conditional result was False 2025-11-09 00:21:24.968796 | controller | skipping: Conditional result was False 2025-11-09 00:21:25.021577 | 2025-11-09 00:21:25.021745 | PLAY [localhost] 2025-11-09 00:21:25.041562 | 2025-11-09 00:21:25.041721 | TASK [Run Zuul manifest role] 2025-11-09 00:21:25.062084 | localhost | ok 2025-11-09 00:21:25.077144 | 2025-11-09 00:21:25.077256 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-09 00:21:25.509655 | localhost | changed 2025-11-09 00:21:25.520576 | 2025-11-09 00:21:25.520763 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-09 00:21:25.560436 | localhost | ok 2025-11-09 00:21:25.583141 | 2025-11-09 00:21:25.583304 | TASK [Set zuul-log-path fact] 2025-11-09 00:21:25.652915 | localhost | ok 2025-11-09 00:21:25.681033 | 2025-11-09 00:21:25.681250 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-09 00:21:25.725330 | localhost | ok 2025-11-09 00:21:25.735216 | 2025-11-09 00:21:25.735358 | LOOP [Run upload-logs-swift role] 2025-11-09 00:21:25.781481 | localhost | Output suppressed because no_log was given 2025-11-09 00:21:25.821615 | 2025-11-09 00:21:25.821749 | TASK [Set zuul-log-path fact] 2025-11-09 00:21:25.846998 | localhost | skipping: Conditional result was False 2025-11-09 00:21:25.854754 | 2025-11-09 00:21:25.854846 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-09 00:21:26.299094 | localhost -> localhost | ok: Runtime: 0:00:00.006946 2025-11-09 00:21:26.306350 | 2025-11-09 00:21:26.306473 | TASK [upload-logs-swift : Upload logs to swift]