2025-11-20 00:40:17.536715 | Job console starting... 2025-11-20 00:40:17.551213 | Updating repositories 2025-11-20 00:40:17.696050 | Preparing job workspace 2025-11-20 00:40:21.805883 | Running Ansible setup... 2025-11-20 00:40:27.107608 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-20 00:40:27.759733 | 2025-11-20 00:40:27.759905 | PLAY [localhost] 2025-11-20 00:40:27.771068 | 2025-11-20 00:40:27.771189 | TASK [Gathering Facts] 2025-11-20 00:40:28.789594 | localhost | ok 2025-11-20 00:40:28.805071 | 2025-11-20 00:40:28.805208 | TASK [Setup log path fact] 2025-11-20 00:40:28.825792 | localhost | ok 2025-11-20 00:40:28.847728 | 2025-11-20 00:40:28.847891 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-20 00:40:28.877693 | localhost | ok 2025-11-20 00:40:28.886292 | 2025-11-20 00:40:28.886386 | TASK [emit-job-header : Print job information] 2025-11-20 00:40:28.924820 | # Job Information 2025-11-20 00:40:28.925096 | Ansible Version: 2.15.12 2025-11-20 00:40:28.925133 | Job: ansible-test-sanity-docker-stable-2.11 2025-11-20 00:40:28.925156 | Pipeline: periodic 2025-11-20 00:40:28.925176 | Executor: ze01.softwarefactory-project.io 2025-11-20 00:40:28.925194 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-11-20 00:40:28.925216 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/f69/ansible/f69c21c881f942f9951a4109f70a73f9/ 2025-11-20 00:40:28.925235 | Event ID: 4015b71040db4124b5e62c0aaaa553e0 2025-11-20 00:40:28.928795 | 2025-11-20 00:40:28.928856 | LOOP [emit-job-header : Print node information] 2025-11-20 00:40:29.037717 | localhost | ok: 2025-11-20 00:40:29.037983 | localhost | # Node Information 2025-11-20 00:40:29.038065 | localhost | Inventory Hostname: controller 2025-11-20 00:40:29.038097 | localhost | Hostname: np0005528767 2025-11-20 00:40:29.038118 | localhost | Username: zuul 2025-11-20 00:40:29.038184 | localhost | Distro: Fedora 37 2025-11-20 00:40:29.038211 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-11-20 00:40:29.038229 | localhost | Region: ca-ymq-1 2025-11-20 00:40:29.038247 | localhost | Label: ansible-fedora-37-1vcpu 2025-11-20 00:40:29.038265 | localhost | Product Name: OpenStack Nova 2025-11-20 00:40:29.038282 | localhost | Interface IP: 162.253.55.206 2025-11-20 00:40:29.065572 | 2025-11-20 00:40:29.065760 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-11-20 00:40:29.563959 | localhost -> localhost | changed 2025-11-20 00:40:29.569729 | 2025-11-20 00:40:29.569829 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-11-20 00:40:30.595848 | localhost -> localhost | changed 2025-11-20 00:40:30.623720 | 2025-11-20 00:40:30.623827 | PLAY [all:!appliance*] 2025-11-20 00:40:30.648971 | 2025-11-20 00:40:30.649137 | TASK [include_role : start-zuul-console] 2025-11-20 00:40:30.670744 | controller | ok 2025-11-20 00:40:30.686217 | 2025-11-20 00:40:30.686359 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-11-20 00:40:31.087083 | controller | ok 2025-11-20 00:40:31.099803 | 2025-11-20 00:40:31.099946 | TASK [use-our-mirror : Retrieve the IP address] 2025-11-20 00:40:32.146590 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-11-20 00:40:32.153802 | 2025-11-20 00:40:32.153917 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-11-20 00:40:32.687519 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.694377 | 2025-11-20 00:40:32.694476 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-11-20 00:40:32.718947 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.725331 | 2025-11-20 00:40:32.725415 | TASK [use-our-mirror : Create the podman configuration directory] 2025-11-20 00:40:32.749623 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.756378 | 2025-11-20 00:40:32.756512 | TASK [use-our-mirror : Copy the podman configuration] 2025-11-20 00:40:32.780859 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.788454 | 2025-11-20 00:40:32.788610 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-11-20 00:40:32.813372 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.821973 | 2025-11-20 00:40:32.822124 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-11-20 00:40:32.837476 | controller | skipping: Conditional result was False 2025-11-20 00:40:32.852830 | 2025-11-20 00:40:32.852977 | TASK [Disable Fedora Modular] 2025-11-20 00:40:33.108817 | controller | changed 2025-11-20 00:40:33.114870 | 2025-11-20 00:40:33.114941 | TASK [Enable EPEL] 2025-11-20 00:40:33.139550 | controller | skipping: Conditional result was False 2025-11-20 00:40:33.146058 | 2025-11-20 00:40:33.146149 | TASK [Register the RHEL node] 2025-11-20 00:40:33.690653 | 2025-11-20 00:40:33.690834 | TASK [Show the subscription-manager status] 2025-11-20 00:40:34.269460 | controller | skipping: Conditional result was False 2025-11-20 00:40:34.278926 | 2025-11-20 00:40:34.279105 | TASK [Enable EPEL on RHEL] 2025-11-20 00:40:34.822680 | controller | skipping: Conditional result was False 2025-11-20 00:40:34.837730 | 2025-11-20 00:40:34.837932 | TASK [Install git and tox] 2025-11-20 00:42:00.759408 | controller | changed 2025-11-20 00:42:00.781571 | 2025-11-20 00:42:00.781716 | TASK [include_role : prepare-workspace] 2025-11-20 00:42:00.815549 | controller | ok 2025-11-20 00:42:00.840708 | 2025-11-20 00:42:00.840835 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-11-20 00:42:01.085687 | controller | ok 2025-11-20 00:42:01.092976 | 2025-11-20 00:42:01.093077 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-11-20 00:42:14.621595 | controller | Output suppressed because no_log was given 2025-11-20 00:42:14.631999 | 2025-11-20 00:42:14.632097 | TASK [include_role : prepare-workspace-openshift] 2025-11-20 00:42:14.648160 | controller | skipping: Conditional result was False 2025-11-20 00:42:14.701284 | 2025-11-20 00:42:14.701376 | PLAY [all:!appliance] 2025-11-20 00:42:14.723223 | 2025-11-20 00:42:14.723334 | TASK [Run add-build-sshkey role (RSA)] 2025-11-20 00:42:14.743540 | controller | ok 2025-11-20 00:42:14.761358 | 2025-11-20 00:42:14.761468 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-20 00:42:14.990616 | controller -> localhost | ok 2025-11-20 00:42:14.997666 | 2025-11-20 00:42:14.997759 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-20 00:42:15.018206 | controller | ok 2025-11-20 00:42:15.035818 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-20 00:42:15.042507 | 2025-11-20 00:42:15.042599 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-20 00:42:15.571080 | controller -> localhost | Generating public/private rsa key pair. 2025-11-20 00:42:15.571323 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_rsa. 2025-11-20 00:42:15.571355 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_rsa.pub. 2025-11-20 00:42:15.571378 | controller -> localhost | The key fingerprint is: 2025-11-20 00:42:15.571399 | controller -> localhost | SHA256:Z+UIpkI8iFvPAEtd0rDgOwL7+uy2bkesmvuEuPYbTNQ zuul-build-sshkey 2025-11-20 00:42:15.571419 | controller -> localhost | The key's randomart image is: 2025-11-20 00:42:15.571439 | controller -> localhost | +---[RSA 2048]----+ 2025-11-20 00:42:15.571458 | controller -> localhost | |.o.o+. | 2025-11-20 00:42:15.571481 | controller -> localhost | |o+.++. | 2025-11-20 00:42:15.571510 | controller -> localhost | |+.+o+E o . | 2025-11-20 00:42:15.571533 | controller -> localhost | |.+o= . o . + | 2025-11-20 00:42:15.571555 | controller -> localhost | |+o o+ . S + . | 2025-11-20 00:42:15.571613 | controller -> localhost | |oo+ o. o | 2025-11-20 00:42:15.571656 | controller -> localhost | |o o= | 2025-11-20 00:42:15.571680 | controller -> localhost | | B+ o | 2025-11-20 00:42:15.571702 | controller -> localhost | |BXO=. | 2025-11-20 00:42:15.571725 | controller -> localhost | +----[SHA256]-----+ 2025-11-20 00:42:15.571777 | controller -> localhost | ok: Runtime: 0:00:00.138953 2025-11-20 00:42:15.579986 | 2025-11-20 00:42:15.580127 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-20 00:42:15.612699 | controller | ok 2025-11-20 00:42:15.629952 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-20 00:42:15.641903 | 2025-11-20 00:42:15.642087 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-20 00:42:15.667075 | controller | skipping: Conditional result was False 2025-11-20 00:42:15.680226 | 2025-11-20 00:42:15.680397 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-20 00:42:16.145940 | controller | changed 2025-11-20 00:42:16.156644 | 2025-11-20 00:42:16.156813 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-20 00:42:16.393798 | controller | ok 2025-11-20 00:42:16.402475 | 2025-11-20 00:42:16.402882 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-20 00:42:17.019501 | controller | changed 2025-11-20 00:42:17.028923 | 2025-11-20 00:42:17.029080 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-20 00:42:17.660290 | controller | changed 2025-11-20 00:42:17.667063 | 2025-11-20 00:42:17.667154 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-20 00:42:17.681855 | controller | skipping: Conditional result was False 2025-11-20 00:42:17.690064 | 2025-11-20 00:42:17.690176 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-20 00:42:18.124989 | controller -> localhost | changed 2025-11-20 00:42:18.156755 | 2025-11-20 00:42:18.156918 | TASK [add-build-sshkey : Add back temp key] 2025-11-20 00:42:18.448271 | controller -> localhost | Identity added: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_rsa (zuul-build-sshkey) 2025-11-20 00:42:18.448552 | controller -> localhost | ok: Runtime: 0:00:00.008380 2025-11-20 00:42:18.460204 | 2025-11-20 00:42:18.460339 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-20 00:42:18.845229 | controller | ok 2025-11-20 00:42:18.853810 | 2025-11-20 00:42:18.853932 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-20 00:42:18.879764 | controller | skipping: Conditional result was False 2025-11-20 00:42:18.899225 | 2025-11-20 00:42:18.899358 | TASK [Run add-build-sshkey role (ECDSA)] 2025-11-20 00:42:18.925352 | controller | ok 2025-11-20 00:42:18.951159 | 2025-11-20 00:42:18.951282 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-11-20 00:42:19.193345 | controller -> localhost | ok 2025-11-20 00:42:19.211933 | 2025-11-20 00:42:19.212149 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-11-20 00:42:19.242891 | controller | ok 2025-11-20 00:42:19.254867 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-11-20 00:42:19.261356 | 2025-11-20 00:42:19.261425 | TASK [add-build-sshkey : Create Temp SSH key] 2025-11-20 00:42:19.523796 | controller -> localhost | Generating public/private ecdsa key pair. 2025-11-20 00:42:19.523978 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_ecdsa. 2025-11-20 00:42:19.524007 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_ecdsa.pub. 2025-11-20 00:42:19.524067 | controller -> localhost | The key fingerprint is: 2025-11-20 00:42:19.524090 | controller -> localhost | SHA256:rPInJ4I1H2pSujRUvcDMQi1kmc6PhlDTlq+0O7vhU8c zuul-build-sshkey 2025-11-20 00:42:19.524111 | controller -> localhost | The key's randomart image is: 2025-11-20 00:42:19.524130 | controller -> localhost | +---[ECDSA 521]---+ 2025-11-20 00:42:19.524148 | controller -> localhost | | .+= . | 2025-11-20 00:42:19.524166 | controller -> localhost | | o*+=. | 2025-11-20 00:42:19.524184 | controller -> localhost | | +.+*.. | 2025-11-20 00:42:19.524202 | controller -> localhost | |. oo...o | 2025-11-20 00:42:19.524219 | controller -> localhost | |...+ o..S | 2025-11-20 00:42:19.524236 | controller -> localhost | |..o B o.E | 2025-11-20 00:42:19.524255 | controller -> localhost | | .o=o*.o | 2025-11-20 00:42:19.524274 | controller -> localhost | | .+oB++ o | 2025-11-20 00:42:19.524293 | controller -> localhost | | .++*.= | 2025-11-20 00:42:19.524311 | controller -> localhost | +----[SHA256]-----+ 2025-11-20 00:42:19.524355 | controller -> localhost | ok: Runtime: 0:00:00.012519 2025-11-20 00:42:19.532155 | 2025-11-20 00:42:19.532271 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-11-20 00:42:19.557315 | controller | ok 2025-11-20 00:42:19.569688 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-11-20 00:42:19.580863 | 2025-11-20 00:42:19.581464 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-11-20 00:42:19.595857 | controller | skipping: Conditional result was False 2025-11-20 00:42:19.604172 | 2025-11-20 00:42:19.604285 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-11-20 00:42:19.874686 | controller | changed 2025-11-20 00:42:19.887525 | 2025-11-20 00:42:19.887680 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-11-20 00:47:34.849893 | controller | ok 2025-11-20 00:47:34.868556 | 2025-11-20 00:47:34.868771 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-11-20 00:47:35.502317 | controller | changed 2025-11-20 00:47:35.513367 | 2025-11-20 00:47:35.513677 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-11-20 00:47:36.146166 | controller | changed 2025-11-20 00:47:36.152829 | 2025-11-20 00:47:36.152911 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-11-20 00:47:36.177257 | controller | skipping: Conditional result was False 2025-11-20 00:47:36.184826 | 2025-11-20 00:47:36.184950 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-11-20 00:47:36.422966 | controller -> localhost | changed 2025-11-20 00:47:36.436246 | 2025-11-20 00:47:36.436358 | TASK [add-build-sshkey : Add back temp key] 2025-11-20 00:47:36.698218 | controller -> localhost | Identity added: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/f69c21c881f942f9951a4109f70a73f9_id_ecdsa (zuul-build-sshkey) 2025-11-20 00:47:36.698626 | controller -> localhost | ok: Runtime: 0:00:00.007969 2025-11-20 00:47:36.720565 | 2025-11-20 00:47:36.720818 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-11-20 00:47:36.937684 | controller | ok 2025-11-20 00:47:36.956146 | 2025-11-20 00:47:36.956320 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-11-20 00:47:36.984299 | controller | skipping: Conditional result was False 2025-11-20 00:47:37.002113 | 2025-11-20 00:47:37.002238 | TASK [include_role : remove-zuul-sshkey] 2025-11-20 00:47:37.018629 | controller | skipping: Conditional result was False 2025-11-20 00:47:37.030628 | 2025-11-20 00:47:37.030782 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-11-20 00:47:37.252551 | controller | ok: "logs" 2025-11-20 00:47:37.252797 | controller | ok: All items complete 2025-11-20 00:47:37.252827 | 2025-11-20 00:47:37.448835 | controller | ok: "artifacts" 2025-11-20 00:47:37.632556 | controller | ok: "docs" 2025-11-20 00:47:37.655542 | 2025-11-20 00:47:37.655747 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-11-20 00:47:37.900148 | controller | changed: "logs" 2025-11-20 00:47:38.094308 | controller | changed: "artifacts" 2025-11-20 00:47:38.286424 | controller | changed: "docs" 2025-11-20 00:47:38.316762 | 2025-11-20 00:47:38.316857 | PLAY RECAP 2025-11-20 00:47:38.316902 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-11-20 00:47:38.316931 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-11-20 00:47:38.316950 | 2025-11-20 00:47:38.481397 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-11-20 00:47:38.482420 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-20 00:47:39.113546 | 2025-11-20 00:47:39.113677 | PLAY [all] 2025-11-20 00:47:39.156393 | 2025-11-20 00:47:39.156516 | TASK [Install binary dependencies] 2025-11-20 00:47:39.205910 | controller | ok 2025-11-20 00:47:39.239903 | 2025-11-20 00:47:39.240063 | TASK [bindep : Include find tasks] 2025-11-20 00:47:39.268935 | controller | ok 2025-11-20 00:47:39.277405 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-11-20 00:47:39.283549 | 2025-11-20 00:47:39.283613 | TASK [bindep : Look for bindep.txt] 2025-11-20 00:47:39.816911 | controller | ok 2025-11-20 00:47:39.832230 | 2025-11-20 00:47:39.832400 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:47:39.859600 | controller | skipping: Conditional result was False 2025-11-20 00:47:39.868980 | 2025-11-20 00:47:39.869108 | TASK [bindep : Look for other-requirements.txt] 2025-11-20 00:47:40.086851 | controller | ok 2025-11-20 00:47:40.094613 | 2025-11-20 00:47:40.094698 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:47:40.129313 | controller | skipping: Conditional result was False 2025-11-20 00:47:40.142849 | 2025-11-20 00:47:40.143010 | TASK [bindep : Look for bindep fallback file] 2025-11-20 00:47:40.179993 | controller | skipping: Conditional result was False 2025-11-20 00:47:40.196816 | 2025-11-20 00:47:40.197009 | TASK [bindep : Define bindep_file fact] 2025-11-20 00:47:40.233488 | controller | skipping: Conditional result was False 2025-11-20 00:47:40.248650 | 2025-11-20 00:47:40.248822 | TASK [bindep : Include bindep tasks] 2025-11-20 00:47:40.275262 | controller | skipping: Conditional result was False 2025-11-20 00:47:40.289781 | 2025-11-20 00:47:40.289958 | TASK [bindep : Include install tasks] 2025-11-20 00:47:40.316267 | controller | skipping: Conditional result was False 2025-11-20 00:47:40.325532 | 2025-11-20 00:47:40.325711 | LOOP [bindep : Include package tasks] 2025-11-20 00:47:40.405202 | 2025-11-20 00:47:40.405472 | TASK [Run test-setup role] 2025-11-20 00:47:40.431458 | controller | ok 2025-11-20 00:47:40.459206 | 2025-11-20 00:47:40.459384 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-11-20 00:47:40.665361 | controller | ok 2025-11-20 00:47:40.672136 | 2025-11-20 00:47:40.672229 | TASK [test-setup : Run tools/test-setup.sh] 2025-11-20 00:47:41.208039 | controller | skipping: Conditional result was False 2025-11-20 00:47:41.242871 | 2025-11-20 00:47:41.242994 | PLAY RECAP 2025-11-20 00:47:41.243084 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-20 00:47:41.243153 | 2025-11-20 00:47:41.356260 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-11-20 00:47:41.357509 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-20 00:47:42.046108 | 2025-11-20 00:47:42.046267 | PLAY [controller] 2025-11-20 00:47:42.068957 | 2025-11-20 00:47:42.069113 | TASK [Create the /root directory] 2025-11-20 00:47:42.679590 | controller | ok 2025-11-20 00:47:42.693102 | 2025-11-20 00:47:42.693314 | TASK [Install glibc-langpack-en] 2025-11-20 00:47:46.785838 | controller | ok: Nothing to do 2025-11-20 00:47:46.801702 | 2025-11-20 00:47:46.801851 | TASK [Ensure controller directory exists] 2025-11-20 00:47:47.067171 | controller | changed 2025-11-20 00:47:47.085796 | 2025-11-20 00:47:47.085988 | TASK [Install container runtime] 2025-11-20 00:47:47.144506 | controller | ok 2025-11-20 00:47:47.231478 | 2025-11-20 00:47:47.231613 | LOOP [ensure-docker : Gather variables for each operating system] 2025-11-20 00:47:47.268978 | controller | ok: "/var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/vars/fedora.yaml" 2025-11-20 00:47:47.286611 | 2025-11-20 00:47:47.286756 | TASK [ensure-docker : Sanity check for distro selection] 2025-11-20 00:47:47.300766 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.310993 | 2025-11-20 00:47:47.311168 | TASK [ensure-docker : Sanity check for distro install] 2025-11-20 00:47:47.337406 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.347190 | 2025-11-20 00:47:47.347346 | TASK [ensure-docker : Sanity check for upstream install] 2025-11-20 00:47:47.373129 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.380683 | 2025-11-20 00:47:47.380789 | TASK [ensure-docker : Sanity check for upstream install mirrors] 2025-11-20 00:47:47.405058 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.414219 | 2025-11-20 00:47:47.414340 | TASK [ensure-docker : Include tasks for docker install] 2025-11-20 00:47:47.437378 | controller | ok 2025-11-20 00:47:47.460848 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-upstream.yaml 2025-11-20 00:47:47.472072 | 2025-11-20 00:47:47.472192 | TASK [ensure-docker : Not Implemented] 2025-11-20 00:47:47.496748 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.507943 | 2025-11-20 00:47:47.508125 | TASK [Set up docker mirrors] 2025-11-20 00:47:47.535162 | controller | ok 2025-11-20 00:47:47.564525 | 2025-11-20 00:47:47.564656 | TASK [use-docker-mirror : Set docker_mirror fact from mirror_info] 2025-11-20 00:47:47.599101 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.606162 | 2025-11-20 00:47:47.606270 | TASK [use-docker-mirror : Set docker_mirror fact from zuul_site_mirror_info] 2025-11-20 00:47:47.640801 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.648382 | 2025-11-20 00:47:47.648490 | TASK [use-docker-mirror : Set docker_mirror fact] 2025-11-20 00:47:47.683072 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.689973 | 2025-11-20 00:47:47.690103 | TASK [use-docker-mirror : Set up docker mirrors] 2025-11-20 00:47:47.724437 | controller | skipping: Conditional result was False 2025-11-20 00:47:47.737061 | 2025-11-20 00:47:47.737178 | TASK [Add all repositories] 2025-11-20 00:47:47.756937 | controller | ok 2025-11-20 00:47:47.782545 | 2025-11-20 00:47:47.782707 | LOOP [ensure-package-repositories : Install repositories] 2025-11-20 00:47:47.806358 | controller | ok: "/var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml" 2025-11-20 00:47:47.806623 | controller | ok: All items complete 2025-11-20 00:47:47.806653 | 2025-11-20 00:47:47.858963 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-package-repositories/tasks/RedHat.yaml 2025-11-20 00:47:47.865952 | 2025-11-20 00:47:47.866063 | TASK [ensure-package-repositories : Create GPG key temp directory] 2025-11-20 00:47:48.210358 | controller | changed 2025-11-20 00:47:48.225406 | 2025-11-20 00:47:48.225550 | LOOP [ensure-package-repositories : Upload GPG keys] 2025-11-20 00:47:49.155236 | controller | changed: 2025-11-20 00:47:49.155553 | controller | { 2025-11-20 00:47:49.155594 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2025-11-20 00:47:49.155628 | controller | } 2025-11-20 00:47:49.178736 | 2025-11-20 00:47:49.178982 | LOOP [ensure-package-repositories : Import GPG keys] 2025-11-20 00:47:49.888503 | controller | changed: 2025-11-20 00:47:49.888852 | controller | { 2025-11-20 00:47:49.888936 | controller | "data": "-----BEGIN PGP PUBLIC KEY BLOCK-----\n\nmQINBFit5IEBEADDt86QpYKz5flnCsOyZ/fk3WwBKxfDjwHf/GIflo+4GWAXS7wJ\n1PSzPsvSDATV10J44i5WQzh99q+lZvFCVRFiNhRmlmcXG+rk1QmDh3fsCCj9Q/yP\nw8jn3Hx0zDtz8PIB/18ReftYJzUo34COLiHn8WiY20uGCF2pjdPgfxE+K454c4G7\ngKFqVUFYgPug2CS0quaBB5b0rpFUdzTeI5RCStd27nHCpuSDCvRYAfdv+4Y1yiVh\nKKdoe3Smj+RnXeVMgDxtH9FJibZ3DK7WnMN2yeob6VqXox+FvKYJCCLkbQgQmE50\nuVK0uN71A1mQDcTRKQ2q3fFGlMTqJbbzr3LwnCBE6hV0a36t+DABtZTmz5O69xdJ\nWGdBeePCnWVqtDb/BdEYz7hPKskcZBarygCCe2Xi7sZieoFZuq6ltPoCsdfEdfbO\n+VBVKJnExqNZCcFUTEnbH4CldWROOzMS8BGUlkGpa59Sl1t0QcmWlw1EbkeMQNrN\nspdR8lobcdNS9bpAJQqSHRZh3cAM9mA3Yq/bssUS/P2quRXLjJ9mIv3dky9C3udM\n+q2unvnbNpPtIUly76FJ3s8g8sHeOnmYcKqNGqHq2Q3kMdA2eIbI0MqfOIo2+Xk0\nrNt3ctq3g+cQiorcN3rdHPsTRSAcp+NCz1QF9TwXYtH1XV24A6QMO0+CZwARAQAB\ntCtEb2NrZXIgUmVsZWFzZSAoQ0UgcnBtKSA8ZG9ja2VyQGRvY2tlci5jb20+iQI3\nBBMBCgAhBQJYrep4AhsvBQsJCAcDBRUKCQgLBRYCAwEAAh4BAheAAAoJEMUv62ti\nHp816C0P/iP+1uhSa6Qq3TIc5sIFE5JHxOO6y0R97cUdAmCbEqBiJHUPNQDQaaRG\nVYBm0K013Q1gcJeUJvS32gthmIvhkstw7KTodwOM8Kl11CCqZ07NPFef1b2SaJ7l\nTYpyUsT9+e343ph+O4C1oUQw6flaAJe+8ATCmI/4KxfhIjD2a/Q1voR5tUIxfexC\n/LZTx05gyf2mAgEWlRm/cGTStNfqDN1uoKMlV+WFuB1j2oTUuO1/dr8mL+FgZAM3\nntWFo9gQCllNV9ahYOON2gkoZoNuPUnHsf4Bj6BQJnIXbAhMk9H2sZzwUi9bgObZ\nXO8+OrP4D4B9kCAKqqaQqA+O46LzO2vhN74lm/Fy6PumHuviqDBdN+HgtRPMUuao\nxnuVJSvBu9sPdgT/pR1N9u/KnfAnnLtR6g+fx4mWz+ts/riB/KRHzXd+44jGKZra\nIhTMfniguMJNsyEOO0AN8Tqcl0eRBxcOArcri7xu8HFvvl+e+ILymu4buusbYEVL\nGBkYP5YMmScfKn+jnDVN4mWoN1Bq2yMhMGx6PA3hOvzPNsUoYy2BwDxNZyflzuAi\ng59mgJm2NXtzNbSRJbMamKpQ69mzLWGdFNsRd4aH7PT7uPAURaf7B5BVp3UyjERW\n5alSGnBqsZmvlRnVH5BDUhYsWZMPRQS9rRr4iGW0l+TH+O2VJ8aQ\n=0Zqq\n-----END PGP PUBLIC KEY BLOCK-----\n" 2025-11-20 00:47:49.889057 | controller | } 2025-11-20 00:47:49.889157 | controller | changed: All items complete 2025-11-20 00:47:49.889227 | 2025-11-20 00:47:49.908437 | 2025-11-20 00:47:49.908662 | TASK [ensure-package-repositories : Remove GPG temp directory] 2025-11-20 00:47:50.160397 | controller | changed 2025-11-20 00:47:50.170302 | 2025-11-20 00:47:50.170455 | LOOP [ensure-package-repositories : Add repositories] 2025-11-20 00:47:50.498305 | controller | changed: 2025-11-20 00:47:50.498542 | controller | { 2025-11-20 00:47:50.498589 | controller | "baseurl": "https://download.docker.com/linux/fedora/$releasever/$basearch/stable", 2025-11-20 00:47:50.498627 | controller | "description": "Docker CE Stable - $basearch", 2025-11-20 00:47:50.498658 | controller | "gpgcheck": true, 2025-11-20 00:47:50.498690 | controller | "name": "docker-ce-stable" 2025-11-20 00:47:50.498722 | controller | } 2025-11-20 00:47:50.528982 | 2025-11-20 00:47:50.529212 | TASK [ensure-docker : Install pre-reqs] 2025-11-20 00:47:52.024257 | controller | ok: Nothing to do 2025-11-20 00:47:52.030358 | 2025-11-20 00:47:52.030424 | TASK [ensure-docker : Remove packages] 2025-11-20 00:47:54.459731 | controller | ok: Nothing to do 2025-11-20 00:47:54.469320 | 2025-11-20 00:47:54.469425 | TASK [ensure-docker : Install upstream docker using package] 2025-11-20 00:48:43.112441 | controller | changed 2025-11-20 00:48:43.125532 | 2025-11-20 00:48:43.125667 | TASK [ensure-docker : Setup docker] 2025-11-20 00:48:43.149931 | controller | ok 2025-11-20 00:48:43.163591 | controller | included: /var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-docker/tasks/docker-setup.yaml 2025-11-20 00:48:43.180538 | 2025-11-20 00:48:43.180634 | TASK [ensure-docker : Ensure "docker" group exists] 2025-11-20 00:48:43.648346 | controller | ok 2025-11-20 00:48:43.658421 | 2025-11-20 00:48:43.658544 | TASK [ensure-docker : Add user to docker group] 2025-11-20 00:48:44.179797 | controller | changed 2025-11-20 00:48:44.186550 | 2025-11-20 00:48:44.186656 | TASK [Update docker daemon proxy configuration] 2025-11-20 00:48:44.222904 | controller | skipping: Conditional result was False 2025-11-20 00:48:44.231227 | 2025-11-20 00:48:44.231332 | TASK [Lower default MTU] 2025-11-20 00:48:44.266726 | controller | skipping: Conditional result was False 2025-11-20 00:48:44.279069 | 2025-11-20 00:48:44.279181 | TASK [ensure-docker : Get the status of the docket.socket unit] 2025-11-20 00:48:44.687398 | controller | inactive 2025-11-20 00:48:44.827280 | controller | ok: Runtime: 0:00:00.013248 2025-11-20 00:48:44.840071 | 2025-11-20 00:48:44.840311 | TASK [ensure-docker : Get the status of the docket unit] 2025-11-20 00:48:45.099490 | controller | inactive 2025-11-20 00:48:45.394314 | controller | ok: Runtime: 0:00:00.015685 2025-11-20 00:48:45.400738 | 2025-11-20 00:48:45.400809 | TASK [ensure-docker : Restart docker] 2025-11-20 00:48:45.449811 | Trigger a Docker restart 2025-11-20 00:48:45.466578 | 2025-11-20 00:48:45.467064 | TASK [ensure-docker : Reset ssh connection to pick up docker group] 2025-11-20 00:48:45.516619 | 2025-11-20 00:48:45.516991 | TASK [ensure-docker : Install docker-compose] 2025-11-20 00:48:45.543035 | controller | skipping: Conditional result was False 2025-11-20 00:48:45.552528 | 2025-11-20 00:48:45.552665 | TASK [ensure-docker : Flush handlers before role exit] 2025-11-20 00:48:45.566622 | 2025-11-20 00:48:45.566828 | TASK [ensure-docker : Stop docker.socket to avoid any conflict] 2025-11-20 00:48:46.759591 | controller | changed 2025-11-20 00:48:46.778868 | 2025-11-20 00:48:46.779598 | TASK [ensure-docker : Assure docker service is running] 2025-11-20 00:48:48.567266 | controller | changed 2025-11-20 00:48:48.591879 | 2025-11-20 00:48:48.592085 | TASK [ensure-docker : Assure docker.socket service is running] 2025-11-20 00:48:49.620557 | controller | ok 2025-11-20 00:48:49.641086 | 2025-11-20 00:48:49.641216 | TASK [ensure-docker : Correct group ownership on docker sock] 2025-11-20 00:48:50.246815 | controller | ok 2025-11-20 00:48:50.268368 | 2025-11-20 00:48:50.268530 | TASK [ensure-docker : Validate ability to talk with docker] 2025-11-20 00:48:50.838468 | controller | CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 2025-11-20 00:48:51.329895 | controller | ok: Runtime: 0:00:00.053482 2025-11-20 00:48:51.335837 | 2025-11-20 00:48:51.335914 | TASK [ensure-docker : Get version details] 2025-11-20 00:48:51.717910 | controller | Client: Docker Engine - Community 2025-11-20 00:48:51.718054 | controller | Version: 24.0.7 2025-11-20 00:48:51.718091 | controller | API version: 1.43 2025-11-20 00:48:51.718133 | controller | Go version: go1.20.10 2025-11-20 00:48:51.718172 | controller | Git commit: afdd53b 2025-11-20 00:48:51.718222 | controller | Built: Thu Oct 26 09:09:39 2023 2025-11-20 00:48:51.718260 | controller | OS/Arch: linux/amd64 2025-11-20 00:48:51.718309 | controller | Context: default 2025-11-20 00:48:51.718325 | controller | 2025-11-20 00:48:51.718372 | controller | Server: Docker Engine - Community 2025-11-20 00:48:51.718405 | controller | Engine: 2025-11-20 00:48:51.718525 | controller | Version: 24.0.7 2025-11-20 00:48:51.718558 | controller | API version: 1.43 (minimum version 1.12) 2025-11-20 00:48:51.718599 | controller | Go version: go1.20.10 2025-11-20 00:48:51.718629 | controller | Git commit: 311b9ff 2025-11-20 00:48:51.718674 | controller | Built: Thu Oct 26 09:08:11 2023 2025-11-20 00:48:51.718710 | controller | OS/Arch: linux/amd64 2025-11-20 00:48:51.718750 | controller | Experimental: false 2025-11-20 00:48:51.718769 | controller | containerd: 2025-11-20 00:48:51.718875 | controller | Version: 1.6.25 2025-11-20 00:48:51.718908 | controller | GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f 2025-11-20 00:48:51.718938 | controller | runc: 2025-11-20 00:48:51.719010 | controller | Version: 1.1.10 2025-11-20 00:48:51.719042 | controller | GitCommit: v1.1.10-0-g18a0cb0 2025-11-20 00:48:51.719062 | controller | docker-init: 2025-11-20 00:48:51.719124 | controller | Version: 0.19.0 2025-11-20 00:48:51.719167 | controller | GitCommit: de40ad0 2025-11-20 00:48:51.868990 | controller | ok: Runtime: 0:00:00.026617 2025-11-20 00:48:51.883549 | 2025-11-20 00:48:51.883709 | TASK [ensure-docker : Dump installed docker details] 2025-11-20 00:48:51.926125 | {'changed': True, 'stdout': 'Client: Docker Engine - Community\n Version: 24.0.7\n API version: 1.43\n Go version: go1.20.10\n Git commit: afdd53b\n Built: Thu Oct 26 09:09:39 2023\n OS/Arch: linux/amd64\n Context: default\n\nServer: Docker Engine - Community\n Engine:\n Version: 24.0.7\n API version: 1.43 (minimum version 1.12)\n Go version: go1.20.10\n Git commit: 311b9ff\n Built: Thu Oct 26 09:08:11 2023\n OS/Arch: linux/amd64\n Experimental: false\n containerd:\n Version: 1.6.25\n GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f\n runc:\n Version: 1.1.10\n GitCommit: v1.1.10-0-g18a0cb0\n docker-init:\n Version: 0.19.0\n GitCommit: de40ad0', 'stderr': '', 'rc': 0, 'cmd': ['docker', 'version'], 'start': '2025-11-20 00:48:51.694103', 'end': '2025-11-20 00:48:51.720720', 'delta': '0:00:00.026617', 'msg': '', 'zuul_log_id': 'fa163ec2-ffbe-d270-47d0-000000000061-1-controller', 'stdout_lines': ['Client: Docker Engine - Community', ' Version: 24.0.7', ' API version: 1.43', ' Go version: go1.20.10', ' Git commit: afdd53b', ' Built: Thu Oct 26 09:09:39 2023', ' OS/Arch: linux/amd64', ' Context: default', '', 'Server: Docker Engine - Community', ' Engine:', ' Version: 24.0.7', ' API version: 1.43 (minimum version 1.12)', ' Go version: go1.20.10', ' Git commit: 311b9ff', ' Built: Thu Oct 26 09:08:11 2023', ' OS/Arch: linux/amd64', ' Experimental: false', ' containerd:', ' Version: 1.6.25', ' GitCommit: d8f198a4ed8892c764191ef7b3b06d8a2eeb5c7f', ' runc:', ' Version: 1.1.10', ' GitCommit: v1.1.10-0-g18a0cb0', ' docker-init:', ' Version: 0.19.0', ' GitCommit: de40ad0'], 'stderr_lines': [], 'failed': False} 2025-11-20 00:48:51.940754 | 2025-11-20 00:48:51.940892 | TASK [Use buildset registry] 2025-11-20 00:48:51.969920 | controller | skipping: Conditional result was False 2025-11-20 00:48:52.000357 | 2025-11-20 00:48:52.000562 | TASK [Ensure python3.8 is present] 2025-11-20 00:48:52.027680 | controller | skipping: Conditional result was False 2025-11-20 00:48:52.042163 | 2025-11-20 00:48:52.042296 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-11-20 00:48:52.072615 | controller | ok 2025-11-20 00:48:52.106513 | 2025-11-20 00:48:52.106657 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-11-20 00:48:54.211786 | controller | ok: Nothing to do 2025-11-20 00:48:54.217696 | 2025-11-20 00:48:54.217761 | TASK [our-ensure-python : Also install python3-devel] 2025-11-20 00:49:06.763777 | controller | changed 2025-11-20 00:49:06.795985 | 2025-11-20 00:49:06.796173 | TASK [Run ensure-virtualenv role] 2025-11-20 00:49:06.822862 | controller | ok 2025-11-20 00:49:06.864794 | 2025-11-20 00:49:06.864943 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-11-20 00:49:07.097479 | controller | /usr/bin/virtualenv 2025-11-20 00:49:07.403501 | controller | ok: Runtime: 0:00:00.003450 2025-11-20 00:49:07.418935 | 2025-11-20 00:49:07.419246 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-11-20 00:49:07.462138 | controller | skipping: Conditional result was False 2025-11-20 00:49:07.462422 | controller | changed: All items complete 2025-11-20 00:49:07.462452 | 2025-11-20 00:49:07.494685 | 2025-11-20 00:49:07.494831 | TASK [Find the full path of the Python interpreter] 2025-11-20 00:49:07.720200 | controller | /usr/bin/python3.9 2025-11-20 00:49:08.037747 | controller | ok 2025-11-20 00:49:08.043709 | 2025-11-20 00:49:08.043792 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-11-20 00:49:09.592046 | controller | created virtual environment CPython3.9.18.final.0-64 in 876ms 2025-11-20 00:49:09.655256 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-11-20 00:49:09.655301 | 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:49:09.655316 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-11-20 00:49:09.655331 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-11-20 00:49:10.080851 | controller | changed 2025-11-20 00:49:10.093973 | 2025-11-20 00:49:10.094186 | TASK [Set selinux package] 2025-11-20 00:49:10.127475 | controller | ok 2025-11-20 00:49:10.142674 | 2025-11-20 00:49:10.142903 | TASK [Set selinux package (Fedora)] 2025-11-20 00:49:10.187032 | controller | ok 2025-11-20 00:49:10.194858 | 2025-11-20 00:49:10.194993 | TASK [Install selinux into virtualenv] 2025-11-20 00:49:13.598558 | controller | Collecting selinux-please-lie-to-me 2025-11-20 00:49:13.641323 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-11-20 00:49:14.679320 | controller | Collecting setuptools<50.0.0 2025-11-20 00:49:14.688023 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-11-20 00:49:14.739857 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 19.7 MB/s eta 0:00:00 2025-11-20 00:49:14.886788 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-11-20 00:49:14.888714 | controller | Attempting uninstall: setuptools 2025-11-20 00:49:14.897002 | controller | Found existing installation: setuptools 62.6.0 2025-11-20 00:49:14.971015 | controller | Uninstalling setuptools-62.6.0: 2025-11-20 00:49:14.979293 | controller | Successfully uninstalled setuptools-62.6.0 2025-11-20 00:49:15.845995 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-11-20 00:49:16.146672 | controller | 2025-11-20 00:49:16.380848 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-20 00:49:16.380884 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-11-20 00:49:16.746731 | controller | ok: Runtime: 0:00:05.665739 2025-11-20 00:49:16.754230 | 2025-11-20 00:49:16.754391 | TASK [Install pytest-forked into virtualenv] 2025-11-20 00:49:18.014660 | controller | Collecting pytest-forked 2025-11-20 00:49:18.103105 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-11-20 00:49:18.174559 | controller | Collecting py 2025-11-20 00:49:18.218676 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-11-20 00:49:18.254464 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.7 MB/s eta 0:00:00 2025-11-20 00:49:18.565658 | controller | Collecting pytest>=3.10 2025-11-20 00:49:18.570968 | controller | Downloading pytest-8.4.2-py3-none-any.whl (365 kB) 2025-11-20 00:49:18.605876 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 11.5 MB/s eta 0:00:00 2025-11-20 00:49:18.752543 | controller | Collecting tomli>=1 2025-11-20 00:49:18.757840 | controller | Downloading tomli-2.3.0-py3-none-any.whl (14 kB) 2025-11-20 00:49:18.840804 | controller | Collecting pluggy<2,>=1.5 2025-11-20 00:49:18.858470 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-11-20 00:49:18.895525 | controller | Collecting iniconfig>=1 2025-11-20 00:49:18.905824 | controller | Downloading iniconfig-2.1.0-py3-none-any.whl (6.0 kB) 2025-11-20 00:49:18.988650 | controller | Collecting exceptiongroup>=1 2025-11-20 00:49:18.995723 | controller | Downloading exceptiongroup-1.3.0-py3-none-any.whl (16 kB) 2025-11-20 00:49:19.121241 | controller | Collecting pygments>=2.7.2 2025-11-20 00:49:19.131612 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-11-20 00:49:19.154381 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 69.4 MB/s eta 0:00:00 2025-11-20 00:49:19.285328 | controller | Collecting packaging>=20 2025-11-20 00:49:19.295158 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-11-20 00:49:19.306095 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.7 MB/s eta 0:00:00 2025-11-20 00:49:19.445132 | controller | Collecting typing-extensions>=4.6.0 2025-11-20 00:49:19.451668 | controller | Downloading typing_extensions-4.15.0-py3-none-any.whl (44 kB) 2025-11-20 00:49:19.462077 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.6/44.6 kB 5.3 MB/s eta 0:00:00 2025-11-20 00:49:19.682935 | controller | Installing collected packages: typing-extensions, tomli, pygments, py, pluggy, packaging, iniconfig, exceptiongroup, pytest, pytest-forked 2025-11-20 00:49:21.122991 | controller | Successfully installed exceptiongroup-1.3.0 iniconfig-2.1.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0 tomli-2.3.0 typing-extensions-4.15.0 2025-11-20 00:49:21.127387 | controller | 2025-11-20 00:49:21.197408 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-11-20 00:49:21.197448 | controller | [notice] To update, run: /home/zuul/venv/bin/python -m pip install --upgrade pip 2025-11-20 00:49:21.303584 | controller | ok: Runtime: 0:00:03.944193 2025-11-20 00:49:21.309521 | 2025-11-20 00:49:21.309589 | TASK [Update pip] 2025-11-20 00:49:22.823892 | controller | Requirement already satisfied: pip in ./venv/lib/python3.9/site-packages (22.2.2) 2025-11-20 00:49:23.138902 | controller | Collecting pip 2025-11-20 00:49:23.215568 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-11-20 00:49:23.321114 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 17.4 MB/s eta 0:00:00 2025-11-20 00:49:23.472869 | controller | Installing collected packages: pip 2025-11-20 00:49:23.475734 | controller | Attempting uninstall: pip 2025-11-20 00:49:23.480897 | controller | Found existing installation: pip 22.2.2 2025-11-20 00:49:24.004913 | controller | Uninstalling pip-22.2.2: 2025-11-20 00:49:24.045446 | controller | Successfully uninstalled pip-22.2.2 2025-11-20 00:54:31.829113 | controller | ERROR 2025-11-20 00:54:31.830085 | controller | { 2025-11-20 00:54:31.830177 | controller | "msg": "Data could not be sent to remote host \"162.253.55.206\". Make sure this host can be reached over ssh: ssh: connect to host 162.253.55.206 port 22: Connection timed out\r\n", 2025-11-20 00:54:31.830234 | controller | "unreachable": true 2025-11-20 00:54:31.830275 | controller | } unreachable 2025-11-20 00:54:31.834910 | 2025-11-20 00:54:31.835040 | PLAY RECAP 2025-11-20 00:54:31.835137 | controller | ok: 36 changed: 19 unreachable: 1 failed: 0 skipped: 15 rescued: 0 ignored: 0 2025-11-20 00:54:31.835200 | 2025-11-20 00:54:32.019752 | PRE-RUN END RESULT_UNREACHABLE: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-11-20 00:54:32.020798 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-20 00:54:32.621687 | 2025-11-20 00:54:32.621810 | PLAY [all] 2025-11-20 00:54:32.644799 | 2025-11-20 00:54:32.644912 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-11-20 00:54:33.110614 | controller | changed: non-zero return code 2025-11-20 00:54:33.117189 | 2025-11-20 00:54:33.117334 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-11-20 00:54:33.142281 | controller | skipping: Conditional result was False 2025-11-20 00:54:33.151202 | 2025-11-20 00:54:33.151381 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-11-20 00:54:33.184292 | 2025-11-20 00:54:33.184483 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-11-20 00:54:33.215276 | 2025-11-20 00:54:33.215453 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-11-20 00:54:33.239569 | controller | skipping: Conditional result was False 2025-11-20 00:54:33.247621 | 2025-11-20 00:54:33.247770 | LOOP [fetch-subunit-output : Generate subunit file] 2025-11-20 00:54:33.268860 | 2025-11-20 00:54:33.269241 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-11-20 00:54:33.283178 | controller | skipping: Conditional result was False 2025-11-20 00:54:33.290508 | 2025-11-20 00:54:33.290641 | TASK [fetch-subunit-output : Remove the temporary file] 2025-11-20 00:54:33.304925 | controller | skipping: Conditional result was False 2025-11-20 00:54:33.315188 | 2025-11-20 00:54:33.315355 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-11-20 00:54:33.330488 | controller | skipping: Conditional result was False 2025-11-20 00:54:33.367710 | 2025-11-20 00:54:33.367821 | PLAY RECAP 2025-11-20 00:54:33.367869 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-11-20 00:54:33.367893 | 2025-11-20 00:54:33.482718 | POST-RUN END RESULT_UNREACHABLE: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-11-20 00:54:33.483629 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-11-20 00:54:34.165824 | 2025-11-20 00:54:34.165977 | PLAY [all:!appliance*] 2025-11-20 00:54:34.193663 | 2025-11-20 00:54:34.193836 | TASK [unregister the node] 2025-11-20 00:54:34.728396 | controller | skipping: Conditional result was False 2025-11-20 00:54:34.742280 | 2025-11-20 00:54:34.742495 | TASK [include_role : fetch-output] 2025-11-20 00:54:34.811941 | controller | ok 2025-11-20 00:54:34.858939 | 2025-11-20 00:54:34.859184 | TASK [fetch-output : Set log path for multiple nodes] 2025-11-20 00:54:34.937479 | controller | skipping: Conditional result was False 2025-11-20 00:54:34.951808 | 2025-11-20 00:54:34.952000 | TASK [fetch-output : Set log path for single node] 2025-11-20 00:54:34.999778 | controller | ok 2025-11-20 00:54:35.008972 | 2025-11-20 00:54:35.009133 | LOOP [fetch-output : Ensure local output dirs] 2025-11-20 00:54:35.395901 | controller -> localhost | ok: "/var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/logs" 2025-11-20 00:54:35.621716 | controller -> localhost | changed: "/var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/artifacts" 2025-11-20 00:54:35.861705 | controller -> localhost | changed: "/var/lib/zuul/builds/f69c21c881f942f9951a4109f70a73f9/work/docs" 2025-11-20 00:54:35.872412 | 2025-11-20 00:54:35.872531 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-11-20 00:54:36.661495 | controller | changed: 2025-11-20 00:54:36.661727 | controller | .d..t...... ./ 2025-11-20 00:54:36.661774 | controller | cd+++++++++ controller/ 2025-11-20 00:54:36.661825 | controller | changed: All items complete 2025-11-20 00:54:36.661857 | 2025-11-20 00:54:37.182288 | controller | changed: .d..t...... ./ 2025-11-20 00:54:37.697908 | controller | changed: .d..t...... ./ 2025-11-20 00:54:37.732681 | 2025-11-20 00:54:37.732941 | TASK [include_role : fetch-output-openshift] 2025-11-20 00:54:37.759826 | controller | skipping: Conditional result was False 2025-11-20 00:54:37.770131 | 2025-11-20 00:54:37.770266 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-11-20 00:54:37.814883 | controller | skipping: Conditional result was False 2025-11-20 00:54:37.831179 | controller | skipping: Conditional result was False 2025-11-20 00:54:37.880070 | 2025-11-20 00:54:37.880194 | PLAY [localhost] 2025-11-20 00:54:37.901725 | 2025-11-20 00:54:37.901874 | TASK [Run Zuul manifest role] 2025-11-20 00:54:37.921756 | localhost | ok 2025-11-20 00:54:37.936645 | 2025-11-20 00:54:37.936742 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-11-20 00:54:38.317092 | localhost | changed 2025-11-20 00:54:38.321867 | 2025-11-20 00:54:38.321928 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-11-20 00:54:38.349822 | localhost | ok 2025-11-20 00:54:38.357756 | 2025-11-20 00:54:38.357820 | TASK [Set zuul-log-path fact] 2025-11-20 00:54:38.375594 | localhost | ok 2025-11-20 00:54:38.391320 | 2025-11-20 00:54:38.391435 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-11-20 00:54:38.419711 | localhost | ok 2025-11-20 00:54:38.427935 | 2025-11-20 00:54:38.428075 | LOOP [Run upload-logs-swift role] 2025-11-20 00:54:38.462562 | localhost | Output suppressed because no_log was given 2025-11-20 00:54:38.492569 | 2025-11-20 00:54:38.492703 | TASK [Set zuul-log-path fact] 2025-11-20 00:54:38.527552 | localhost | skipping: Conditional result was False 2025-11-20 00:54:38.532632 | 2025-11-20 00:54:38.532694 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-11-20 00:54:38.975942 | localhost -> localhost | ok: Runtime: 0:00:00.007126 2025-11-20 00:54:39.011928 | 2025-11-20 00:54:39.012094 | TASK [upload-logs-swift : Upload logs to swift]