Ansible Galaxy random SSL error: The handshake operation timed out

[aristotelos]

Summary

When installing collections from https://galaxy.ansible.com, the SSL handshake randomly times out. See the following example in which one collection successfully installs and another doesn't:

/ # ansible-galaxy install -r ansible.yml
Starting galaxy collection install process
Process install dependency map
Starting collection install process
Installing 'containers.podman:1.11.0' to '/root/.ansible/collections/ansible_collections/containers/podman'
Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/containers-podman-1.11.0.tar.gz to /root/.ansible/tmp/ansible-local-126eri5wnb3/tmpa07ppuq3
containers.podman (1.11.0) was installed successfully
Installing 'community.general:8.1.0' to '/root/.ansible/collections/ansible_collections/community/general'
Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/community-general-8.1.0.tar.gz to /root/.ansible/tmp/ansible-local-126eri5wnb3/tmpa07ppuq3
ERROR! Unexpected Exception, this is probably a bug: <urlopen error _ssl.c:1074: The handshake operation timed out>
to see the full traceback, use -vvv

It also sometimes fails on the first collection.

Issue Type

Bug Report

Component Name

ansible-galaxy

Ansible Version

$ ansible --version
ansible 2.10.17
  config file = None
  configured module search path = ['/root/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/lib/python3.7/site-packages/ansible
  executable location = /usr/bin/ansible
  python version = 3.7.10 (default, Mar  2 2021, 09:06:08) [GCC 8.3.0]

Configuration

# if using a version older than ansible-core 2.12 you should omit the '-t all'
$ ansible-config dump --only-changed -t all

(No output)

OS / Environment

Alpine 3:10, running on Docker.

Steps to Reproduce

docker run --rm -it alpine:3.10   
# Workaround for https://github.com/alpinelinux/docker-alpine/issues/98
echo -e "https://dl-cdn.alpinelinux.org/alpine/v3.10/main\nhttps://dl-cdn.alpinelinux.org/alpine/v3.10/community" > /etc/apk/repositories 
apk add python3=3.7.10-r0 python3-dev=3.7.10-r0 libffi=3.2.1-r6 gcc=8.3.0-r0 musl-dev=1.1.22-r4 libffi-dev=3.2.1-r6
python3 -m pip install --upgrade pip
python3 -m pip install ansible==2.10
echo -e "---\ncollections:\n  - name: containers.podman\n  - name: community.general\n  - name: ansible.posix" > ansible.yml
ansible-galaxy install -r ansible.yml

Expected Results

The collections should install correctly (have a longer timeout for SSL handshake).

Actual Results

/ # ansible-galaxy install -vvv -r ansible.yml
ansible-galaxy 2.10.17
  config file = None
  configured module search path = ['/root/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/lib/python3.7/site-packages/ansible
  executable location = /usr/bin/ansible-galaxy
  python version = 3.7.10 (default, Mar  2 2021, 09:06:08) [GCC 8.3.0]
No config file found; using defaults
Reading requirement file at '/ansible.yml'
Starting galaxy collection install process
Found installed collection containers.podman:1.11.0 at '/root/.ansible/collections/ansible_collections/containers/podman'
Process install dependency map
Opened /root/.ansible/galaxy_token
Processing requirement collection 'containers.podman'
Collection 'containers.podman' obtained from server default https://galaxy.ansible.com/api/
Processing requirement collection 'community.general'
Collection 'community.general' obtained from server default https://galaxy.ansible.com/api/
Processing requirement collection 'ansible.posix'
Collection 'ansible.posix' obtained from server default https://galaxy.ansible.com/api/
Starting collection install process
Skipping 'containers.podman' as it is already installed
Installing 'community.general:8.1.0' to '/root/.ansible/collections/ansible_collections/community/general'
Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/community-general-8.1.0.tar.gz to /root/.ansible/tmp/ansible-local-136pq1_pd44/tmpx21mnhfu
community.general (8.1.0) was installed successfully
Installing 'ansible.posix:1.5.4' to '/root/.ansible/collections/ansible_collections/ansible/posix'
Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-posix-1.5.4.tar.gz to /root/.ansible/tmp/ansible-local-136pq1_pd44/tmpx21mnhfu
ERROR! Unexpected Exception, this is probably a bug: <urlopen error _ssl.c:1074: The handshake operation timed out>
the full traceback was:

Traceback (most recent call last):
  File "/usr/lib/python3.7/urllib/request.py", line 1350, in do_open
    encode_chunked=req.has_header('Transfer-encoding'))
  File "/usr/lib/python3.7/http/client.py", line 1277, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/lib/python3.7/http/client.py", line 1323, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.7/http/client.py", line 1272, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.7/http/client.py", line 1032, in _send_output
    self.send(msg)
  File "/usr/lib/python3.7/http/client.py", line 972, in send
    self.connect()
  File "/usr/lib/python3.7/site-packages/ansible/module_utils/urls.py", line 446, in connect
    self.sock = self.context.wrap_socket(sock, server_hostname=server_hostname)
  File "/usr/lib/python3.7/ssl.py", line 423, in wrap_socket
    session=session
  File "/usr/lib/python3.7/ssl.py", line 870, in _create
    self.do_handshake()
  File "/usr/lib/python3.7/ssl.py", line 1139, in do_handshake
    self._sslobj.do_handshake()
socket.timeout: _ssl.c:1074: The handshake operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/ansible-galaxy", line 123, in <module>
    exit_code = cli.run()
  File "/usr/lib/python3.7/site-packages/ansible/cli/galaxy.py", line 491, in run
    context.CLIARGS['func']()
  File "/usr/lib/python3.7/site-packages/ansible/cli/galaxy.py", line 1060, in execute_install
    self._execute_install_collection(collection_requirements, collection_path)
  File "/usr/lib/python3.7/site-packages/ansible/cli/galaxy.py", line 1082, in _execute_install_collection
    no_deps, force, force_with_deps, allow_pre_release=allow_pre_release)
  File "/usr/lib/python3.7/site-packages/ansible/galaxy/collection.py", line 695, in install_collections
    collection.install(output_path, b_temp_path)
  File "/usr/lib/python3.7/site-packages/ansible/galaxy/collection.py", line 244, in install
    self.b_path = self.download(b_temp_path)
  File "/usr/lib/python3.7/site-packages/ansible/galaxy/collection.py", line 229, in download
    headers=headers)
  File "/usr/lib/python3.7/site-packages/ansible/galaxy/collection.py", line 1394, in _download_file
    unredirected_headers=['Authorization'], http_agent=user_agent())
  File "/usr/lib/python3.7/site-packages/ansible/module_utils/urls.py", line 1399, in open_url
    unredirected_headers=unredirected_headers)
  File "/usr/lib/python3.7/site-packages/ansible/module_utils/urls.py", line 1304, in open
    return urllib_request.urlopen(request, None, timeout)
  File "/usr/lib/python3.7/urllib/request.py", line 222, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.7/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/usr/lib/python3.7/urllib/request.py", line 641, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/python3.7/urllib/request.py", line 563, in error
    result = self._call_chain(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 755, in http_error_302
    return self.parent.open(new, timeout=req.timeout)
  File "/usr/lib/python3.7/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/usr/lib/python3.7/urllib/request.py", line 641, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/python3.7/urllib/request.py", line 563, in error
    result = self._call_chain(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 755, in http_error_302
    return self.parent.open(new, timeout=req.timeout)
  File "/usr/lib/python3.7/urllib/request.py", line 525, in open
    response = self._open(req, data)
  File "/usr/lib/python3.7/urllib/request.py", line 543, in _open
    '_open', req)
  File "/usr/lib/python3.7/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.7/site-packages/ansible/module_utils/urls.py", line 464, in https_open
    req
  File "/usr/lib/python3.7/urllib/request.py", line 1352, in do_open
    raise URLError(err)
urllib.error.URLError: <urlopen error _ssl.c:1074: The handshake operation timed out>
/ #

Code of Conduct

• I agree to follow the Ansible Code of Conduct

[ansibot]

Files identified in the description:

• bin/ansible-galaxy

If these files are incorrect, please update the component name section of the description or use the component bot command.

[ansibot]

@aristotelos ansible-core 2.10 is not supported and no longer receives bug fixes. Please test against one of the supported versions of ansible-core, preferably the most recent one, to see whether the bug has been fixed.

click here for bot help

[webknjaz]

python3 -m pip install ansible==2.10

That's a very old version that hasn't been supported for a few years. Please, use an up-to-date release instead.
Likewise, Python 3.7 is quite old and is actually EOL since June. That's another outdated bit in your example.

If the issue persists, after the updates / testing against the devel version of ansible-core, then you can use the SSLKEYLOGFILE environment variable to debug the TLS connection in your case (though, it might need https://pypi.org/p/sslkeylog). It's useful when analyzing the network exchange with Wireshark: https://wiki.wireshark.org/TLS.
CPython's ssl module has some nice callback helpers for debugging since Python 3.8: https://hynek.me/til/tls-troubleshooting/#bonus-peeking-into-encrypted-tls-traffic.

It is necessary for us to understand if this is an actual issue in supported versions of ansible-core. If it's not, there's nothing to do but update.