Galaxy: ansible-galaxy collection install timeout

[gundalow]

Bug Report

SUMMARY

We've seen ERROR! Unexpected Exception, this is probably a bug: ('The read operation timed out',) (10 minute time out) quite a few times. Size of the collection doesn't seem to be related.

Is there any logging on Galaxy to see how common this is?

ansible-galaxy -vvv collection install fortinet.fortios
01:49 Downloading https://galaxy.ansible.com/download/fortinet-fortios-1.0.7.tar.gz to /root/.ansible/tmp/ansible-local-666KgfAMW/tmpXSNpnv
# Note 10 minutes have passed
01:59 ERROR! Unexpected Exception, this is probably a bug: ('The read operation timed out',)

STEPS TO REPRODUCE

EXPECTED RESULTS

ACTUAL RESULTS

https://app.shippable.com/github/ansible-collections/community.general/runs/164/3/console

01:40 + ansible-galaxy -vvv collection install fortinet.fortios
01:43 [WARNING]: You are running the development version of Ansible. You should only
01:43 run Ansible from "devel" if you are modifying the Ansible engine, or trying out
01:43 features under development. This is a rapidly changing source of code and can
01:43 become unstable at any point.
01:43 [DEPRECATION WARNING]: Setting verbosity before the arg sub command is 
01:43 deprecated, set the verbosity after the sub command. This feature will be 
01:43 removed in version 2.13. Deprecation warnings can be disabled by setting 
01:43 deprecation_warnings=False in ansible.cfg.
01:43 ansible-galaxy 2.10.0.dev0
01:43   config file = None
01:43   configured module search path = [u'/root/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
01:43   ansible python module location = /root/venv/lib/python2.7/site-packages/ansible
01:43   executable location = /root/venv/bin/ansible-galaxy
01:43   python version = 2.7.15+ (default, Feb  9 2019, 11:33:22) [GCC 5.4.0 20160609]
01:43 No config file found; using defaults
01:43 Found installed collection ansible.posix:0.1.1 at '/root/.ansible/ansible_collections/ansible/posix'
01:43 Found installed collection ansible.netcommon:0.0.2 at '/root/.ansible/ansible_collections/ansible/netcommon'
01:43 Found installed collection community.crypto:0.1.0 at '/root/.ansible/ansible_collections/community/crypto'
01:43 Found installed collection community.kubernetes:0.10.0 at '/root/.ansible/ansible_collections/community/kubernetes'
01:43 [WARNING]: Collection at '/root/.ansible/ansible_collections/community/general'
01:43 does not have a MANIFEST.json file, cannot detect version.
01:43 Found installed collection community.general:* at '/root/.ansible/ansible_collections/community/general'
01:43 Found installed collection f5networks.f5_modules:1.2.1 at '/root/.ansible/ansible_collections/f5networks/f5_modules'
01:43 Found installed collection cisco.intersight:1.0.3 at '/root/.ansible/ansible_collections/cisco/intersight'
01:43 Found installed collection cisco.mso:0.0.4 at '/root/.ansible/ansible_collections/cisco/mso'
01:43 Found installed collection check_point.mgmt:1.0.4 at '/root/.ansible/ansible_collections/check_point/mgmt'
01:43 Found installed collection ovirt.ovirt_collection:1.0.1 at '/root/.ansible/ansible_collections/ovirt/ovirt_collection'
01:43 Process install dependency map
01:43 Processing requirement collection 'fortinet.fortios'
01:43 Opened /root/.ansible/galaxy_token
01:45 Collection 'fortinet.fortios' obtained from server default https://galaxy.ansible.com/api/
01:49 Starting collection install process
01:49 Installing 'fortinet.fortios:1.0.7' to '/root/.ansible/ansible_collections/fortinet/fortios'
01:49 Downloading https://galaxy.ansible.com/download/fortinet-fortios-1.0.7.tar.gz to /root/.ansible/tmp/ansible-local-666KgfAMW/tmpXSNpnv
01:59 ERROR! Unexpected Exception, this is probably a bug: ('The read operation timed out',)
01:59 the full traceback was:
01:59 
01:59 Traceback (most recent call last):
01:59   File "/root/venv/bin/ansible-galaxy", line 123, in <module>
01:59     exit_code = cli.run()
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/cli/galaxy.py", line 479, in run
01:59     context.CLIARGS['func']()
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/cli/galaxy.py", line 990, in execute_install
01:59     no_deps, force, force_deps, context.CLIARGS['allow_pre_release'])
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/galaxy/collection.py", line 601, in install_collections
01:59     collection.install(output_path, b_temp_path)
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/galaxy/collection.py", line 203, in install
01:59     self.b_path = self.download(b_temp_path)
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/galaxy/collection.py", line 188, in download
01:59     headers=headers)
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/galaxy/collection.py", line 1105, in _download_file
01:59     unredirected_headers=['Authorization'], http_agent=user_agent())
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/module_utils/urls.py", line 1383, in open_url
01:59     unredirected_headers=unredirected_headers)
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/module_utils/urls.py", line 1288, in open
01:59     return urllib_request.urlopen(request, None, timeout)
01:59   File "/usr/lib/python2.7/urllib2.py", line 154, in urlopen
01:59     return opener.open(url, data, timeout)
01:59   File "/usr/lib/python2.7/urllib2.py", line 429, in open
01:59     response = self._open(req, data)
01:59   File "/usr/lib/python2.7/urllib2.py", line 447, in _open
01:59     '_open', req)
01:59   File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain
01:59     result = func(*args)
01:59   File "/root/venv/lib/python2.7/site-packages/ansible/module_utils/urls.py", line 448, in https_open
01:59     req
01:59   File "/usr/lib/python2.7/urllib2.py", line 1201, in do_open
01:59     r = h.getresponse(buffering=True)
01:59   File "/usr/lib/python2.7/httplib.py", line 1121, in getresponse
01:59     response.begin()
01:59   File "/usr/lib/python2.7/httplib.py", line 438, in begin
01:59     version, status, reason = self._read_status()
01:59   File "/usr/lib/python2.7/httplib.py", line 394, in _read_status
01:59     line = self.fp.readline(_MAXLINE + 1)
01:59   File "/usr/lib/python2.7/socket.py", line 480, in readline
01:59     data = self._sock.recv(self._rbufsize)
01:59   File "/usr/lib/python2.7/ssl.py", line 772, in recv
01:59     return self.read(buflen)
01:59   File "/usr/lib/python2.7/ssl.py", line 659, in read
01:59     v = self._sslobj.read(len)
01:59 SSLError: ('The read operation timed out',)

[felixfontein]

I've seen this couple of more times in Shippable.

[gundalow]

again just now

00:40 Installing 'community.kubernetes:0.10.0' to '/root/.ansible/ansible_collections/community/kubernetes'
00:51 ERROR! Unexpected Exception, this is probably a bug: The read operation timed out
00:51 to see the full traceback, use -vvv

[gundalow]

Are there any server-side logs that exist (or could be added) so we can see how often this is occurring?
We've hacked around this in Collections CI by attempting the install 3 times, though this just masks the problem.

[gundalow]

If we see this again we should mention it in IRC #ansible-galaxy and @cutwater will look at the logs.

[cognifloyd]

I'm seeing this quite a bit in github actions:
https://github.com/cognifloyd/community.mongodb/runs/1130183174?check_suite_focus=true

I've added some retry logic, but that only partially works.
It looks like ansible-galaxy has a hard-coded 20 second timeout.

https://github.com/ansible/ansible/blob/fa1fb2d13bdf948dc319be57e8465a9ef48c7fe3/lib/ansible/galaxy/api.py#L195-L197

I'll go mention it in #ansible-galaxy

[felixfontein]

Right now it's happening a lot more than usual.

[jainnikhil30]

I have run into this randomly too. This happens both while getting collections from galaxy or AH.

[jrosser]

I see this a lot in openstack-ansible CI and it's likely the most frequent cause of change-unrelated job failures currently.

[hojerst]

We are currently running into the same issue. galaxy.ansible.com seems to answer after about 16 seconds some of the time which causes the timeout in ansible-galaxy command:

-bash$ curl -fL https://galaxy.ansible.com/download/ansible-netcommon-1.3.1-dev6.tar.gz -o ansible-netcommon-1.3.1-dev6.tar.gz; rm ansible-netcommon-1.3.1-dev6.tar.gz
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100  211k  100  211k    0     0   157k      0  0:00:01  0:00:01 --:--:--  157k

-bash$ curl -fL https://galaxy.ansible.com/download/ansible-netcommon-1.3.1-dev6.tar.gz -o ansible-netcommon-1.3.1-dev6.tar.gz; rm ansible-netcommon-1.3.1-dev6.tar.gz
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:--  0:00:15 --:--:--     0
100  211k  100  211k    0     0  13130      0  0:00:16  0:00:16 --:--:--  946k

Is it possible to increase the timeout on client side for the time being?

[gundalow]

Update from the Ansible side, it appears that someone is scraping galaxy.ansible.com on the hour (every hour) which is causing an increased load and other requests to time out. We are adding some logging in API service to log that from HTTP headers to help identify.

[lucastheisen]

This happens pretty consistently for my use case. Specifically, we have a fork of community.general that we use to patch a bug in gitlab_runner. So we configure our requirements:

---
collections:
- name: git+https://github.com/marwatk/community.general.git
  type: git
  version: gitlab-runner-fix

When we run install, it times out on Installing 'google.cloud:1.0.1':

ltheisen@PC:~/git/etl-ansible$ ansible-galaxy collection install --requirements requirements.yml
Starting galaxy collection install process
Process install dependency map
Starting collection install process
Installing 'community.general:2.0.0' to '/mnt/c/Users/ltheisen/git/etl-ansible/ansible_collections/community/general'
Created collection for community.general at /mnt/c/Users/ltheisen/git/etl-ansible/ansible_collections/community/general
community.general (2.0.0) was installed successfully
Installing 'ansible.netcommon:1.4.1' to '/mnt/c/Users/ltheisen/git/etl-ansible/ansible_collections/ansible/netcommon'
Downloading https://galaxy.ansible.com/download/ansible-netcommon-1.4.1.tar.gz to /home/ltheisen/.ansible/tmp/ansible-local-6034j4q6km4e/tmpljq0sbh0
ansible.netcommon (1.4.1) was installed successfully
Installing 'community.kubernetes:1.1.1' to '/mnt/c/Users/ltheisen/git/etl-ansible/ansible_collections/community/kubernetes'
Downloading https://galaxy.ansible.com/download/community-kubernetes-1.1.1.tar.gz to /home/ltheisen/.ansible/tmp/ansible-local-6034j4q6km4e/tmpljq0sbh0
community.kubernetes (1.1.1) was installed successfully
Installing 'google.cloud:1.0.1' to '/mnt/c/Users/ltheisen/git/etl-ansible/ansible_collections/google/cloud'
Downloading https://galaxy.ansible.com/download/google-cloud-1.0.1.tar.gz to /home/ltheisen/.ansible/tmp/ansible-local-6034j4q6km4e/tmpljq0sbh0
ERROR! Unexpected Exception, this is probably a bug: The read operation timed out
to see the full traceback, use -vvv

Further compounded by the fact subsequent attempt to install indicates the collection is _already installed_:

ltheisen@MM233009-PC:~/git/etl-ansible$ ansible-galaxy collection install --requirements requirements.yml
Starting galaxy collection install process
Process install dependency map
Starting collection install process
Skipping 'community.general' as it is already installed

Luckily the transitive deps exist from the original ansible install and we only need the modifications in the collection itself (not its transitive deps), but this makes it hard to automate around because the install command fails so in a script we have to trap/ignore that failure...

[felixfontein]

Right now (and earlier today), timeouts seem to happen a lot more.

[rhysmeister]

Right now (and earlier today), timeouts seem to happen a lot more.

Getting this since yesterday and all the time.

[ebuildy]

Is there any status page or api ?

And any workaround ? maybe a sed to change hardcoded value

[ntimo]

This is super frustrating since it prevents me from deploying DNS changes using my CI/CD pipelines. Because the collections can't be installed. A status page would actually be quite nice. Or a way to install the collections from a private mirror.

[prasadbiarca]

We are seeing this issue and timeouts since this morning happens to be more.

[WaaZaa666]

Same here, AWX unable to fetch collection requirements from galaxy with timeouts.

[felixfontein]

@ntimo if you downloaded the collection tarballs, you can just install them with ansible-galaxy collection install. Maybe even installing from an URL works, never tested that.

[ntimo]

@felixfontein I tried the following requierments.yml for collections:

collections:
- name: git+https://github.com/ansible-collections/community.general
  type: git
  version: 1.3.1
- name: git+https://github.com/ansible-collections/hetzner.hcloud
  type: git
  version: 1.2.1
- name: git+https://github.com/ansible-collections/community.zabbix
  type: git
  version: 1.1.0

but that failed with the following error:

Starting galaxy collection install process
Process install dependency map
ERROR! Unknown error when attempting to call Galaxy at 'https://galaxy.ansible.com/api/v2/collections/ansible/netcommon/versions/?page=9': The read operation timed out

So I will probably also need to install netcommon from GitHub. But this created a "huge" rabbit hole of decencies that you need to include :/ Which is not really user friendly.

[areguera]

I am also presenting this issue when run:

ansible-galaxy collection download awx.awx

it ends with:

ERROR! Unexpected Exception, this is probably a bug: The read operation timed out

The issue has been happening for a while (some months ago) in irregular intervals. Today, however, I've run the ansible-galaxy command several times and all of them return this error. I started to try with ansible-galaxy command when AWX started to fail bringing the collections and consider to download the collections and work with a local copy of them.

[felixfontein]

Luckily all these dependencies will be gone for community.general 2.0.0 :)

[gundalow]

Services behind galaxy.ansible.com were restarted about an hour ago. Also some worker restart thresholds have been increased.

[areguera]

Thank you so much @gundalow . I have run the same ansible-galaxy download command several times today without time out issues.

[serl]

I've been trying to install community.general since yesterday evening. I managed to install part of the dependencies straight away, but then:

$ ansible-galaxy collection install -r requirements.yml
Process install dependency map
Starting collection install process
Skipping 'ansible.netcommon' as it is already installed
Skipping 'google.cloud' as it is already installed
Installing 'community.general:1.3.3' to '/home/me/.ansible/collections/ansible_collections/community/general'
ERROR! Unexpected Exception, this is probably a bug: ('The read operation timed out',)

By adding -vvv and wgeting the actual package url, it looks like there is a redirect to S3, which answers after some delay.

What worked for me was to change the default 10 seconds delay to 30 seconds in open_url here: https://github.com/ansible/ansible/blob/7f0eb7ad799e531a8fbe5cc4f46046a4b1aeb093/lib/ansible/module_utils/urls.py#L1524.

Isn't 10 seconds a little too optimistic?

[sugitk]

A customer also reported this issue and I proposed the modification above to increase the timeout, they could resolve their problem.

Do we raise an RFE to ansible/ansible? If customer can configure a timeout values in ansible.cfg or something like that, it may be helpful.