Bug 994164

Summary:	attempting to sync fedora-updates repo ends in error
Product:	[Retired] Pulp	Reporter:	Preethi Thomas <pthomas>
Component:	rpm-support	Assignee:	Michael Hrivnak <mhrivnak>
Status:	CLOSED NOTABUG	QA Contact:	Preethi Thomas <pthomas>
Severity:	unspecified	Docs Contact:
Priority:	urgent
Version:	2.2	CC:	mhrivnak
Target Milestone:	---	Keywords:	Triaged
Target Release:	2.2.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:	988919	Environment:
Last Closed:	2013-08-07 01:30:46 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	988919

Description Preethi Thomas 2013-08-06 15:41:03 UTC

Description of problem: 
Attempting to sync certain repositories fail. An example of a repository that causes this can be found here: http://mirror.cc.vt.edu/pub/fedora/linux/updates/19/x86_64/


Version-Release number of selected component (if applicable): master


How reproducible: Always


Steps to Reproduce:
1. pulp-admin rpm repo create --repo-id=fedora-updates --feed=http://mirror.cc.vt.edu/pub/fedora/linux/updates/19/x86_64/
2.[root@cloud-qe-1-vm-1 ~]#  pulp-admin rpm repo sync run --repo-id=fedora-updates
+----------------------------------------------------------------------+
               Synchronizing Repository [fedora-updates]
+----------------------------------------------------------------------+

This command may be exited by pressing ctrl+c without affecting the actual
operation on the server.

Downloading metadata...
[/]
... failed

[Errno 2] No such file or directory:
u'/var/lib/pulp/working/repos/fedora-updates/importers/yum_importer/tmpq9QnsE/cb
46304d6c4512c2c1bc955e3b476bfe9881f84bfbb978803d31dede789abae6-filelists.xml.gz'



Expected results: A successful sync


Additional info: 
2013-08-06 11:03:57,684 pulp.server.dispatch.task:INFO: FAILURE: Task 5857b59a-12b5-4195-ad52-d455e03045c5: CallRequest: RepoSyncManager.sync(u'fedora-updates', sync_config_override=None)
2013-08-06 11:17:10,075 urllib3.connectionpool:INFO: Starting new HTTP connection (1): mirror.cc.vt.edu
2013-08-06 11:17:10,168 urllib3.connectionpool:INFO: Starting new HTTP connection (1): mirror.cc.vt.edu
2013-08-06 11:17:10,173 urllib3.connectionpool:INFO: Starting new HTTP connection (2): mirror.cc.vt.edu
2013-08-06 11:17:10,176 urllib3.connectionpool:INFO: Starting new HTTP connection (3): mirror.cc.vt.edu
2013-08-06 11:17:10,184 urllib3.connectionpool:INFO: Starting new HTTP connection (4): mirror.cc.vt.edu
2013-08-06 11:17:10,188 urllib3.connectionpool:INFO: Starting new HTTP connection (5): mirror.cc.vt.edu
2013-08-06 11:17:10,230 nectar.downloaders.revent:ERROR: [Errno 111] ECONNREFUSED
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/nectar/downloaders/revent.py", line 148, in _fetch
    response = session.get(request.url, headers=headers)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 310, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 279, in request
    resp = self.send(prep, stream=stream, timeout=timeout, verify=verify, cert=cert, proxies=proxies)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 374, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/adapters.py", line 206, in send
    raise ConnectionError(sockerr)
ConnectionError: [Errno 111] ECONNREFUSED
2013-08-06 11:17:10,231 nectar.downloaders.revent:ERROR: [Errno 111] ECONNREFUSED
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/nectar/downloaders/revent.py", line 148, in _fetch
    response = session.get(request.url, headers=headers)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 310, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 279, in request
    resp = self.send(prep, stream=stream, timeout=timeout, verify=verify, cert=cert, proxies=proxies)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 374, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/adapters.py", line 206, in send
    raise ConnectionError(sockerr)
ConnectionError: [Errno 111] ECONNREFUSED
2013-08-06 11:17:10,232 nectar.downloaders.revent:ERROR: [Errno 111] ECONNREFUSED
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/nectar/downloaders/revent.py", line 148, in _fetch
    response = session.get(request.url, headers=headers)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 310, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 279, in request
    resp = self.send(prep, stream=stream, timeout=timeout, verify=verify, cert=cert, proxies=proxies)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 374, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/adapters.py", line 206, in send
    raise ConnectionError(sockerr)
ConnectionError: [Errno 111] ECONNREFUSED
2013-08-06 11:17:10,234 urllib3.connectionpool:INFO: Starting new HTTP connection (6): mirror.cc.vt.edu
2013-08-06 11:17:10,236 urllib3.connectionpool:INFO: Starting new HTTP connection (7): mirror.cc.vt.edu
2013-08-06 11:17:10,279 nectar.downloaders.revent:ERROR: [Errno 111] ECONNREFUSED
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/nectar/downloaders/revent.py", line 148, in _fetch
    response = session.get(request.url, headers=headers)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 310, in get
    return self.request('GET', url, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 279, in request
    resp = self.send(prep, stream=stream, timeout=timeout, verify=verify, cert=cert, proxies=proxies)
  File "/usr/lib/python2.6/site-packages/requests/sessions.py", line 374, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python2.6/site-packages/requests/adapters.py", line 206, in send
    raise ConnectionError(sockerr)
ConnectionError: [Errno 111] ECONNREFUSED
2013-08-06 11:18:02,535 pulp_rpm.plugins.importers.yum.sync:ERROR: sync failed
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 109, in run
    metadata_files = self.get_metadata()
  File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 203, in get_metadata
    metadata_files.generate_dbs()
  File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/repomd/metadata.py", line 277, in generate_dbs
    xml_file_handle = self.get_metadata_file_handle(filename)
  File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/repomd/metadata.py", line 248, in get_metadata_file_handle
    file_handle = gzip.open(file_path, 'r')
  File "/usr/lib64/python2.6/gzip.py", line 33, in open
    return GzipFile(filename, mode, compresslevel)
  File "/usr/lib64/python2.6/gzip.py", line 79, in __init__
    fileobj = self.myfileobj = __builtin__.open(filename, mode or 'rb')
IOError: [Errno 2] No such file or directory: u'/var/lib/pulp/working/repos/fedora-updates/importers/yum_importer/tmpgD9UYM/01650dd8c1f3b61e1b6898e22e851e99f27fd3ae352520cf73e1633c19bd1101-other.xml.gz'
2013-08-06 11:18:02,573 pulp.server.dispatch.task:ERROR: Importer indicated a failed response
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/dispatch/task.py", line 138, in _run
    result = call(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/managers/repo/sync.py", line 117, in sync
    raise PulpExecutionException(_('Importer indicated a failed response'))
PulpExecutionException: Importer indicated a failed response
2013-08-06 11:18:02,578 pulp.server.dispatch.task:INFO: FAILURE: Task 1f361f2a-e68b-4ac8-80d1-9ca192323bc2: CallRequest: RepoSyncManager.sync(u'fedora-updates', sync_config_override=None)

Comment 1 Michael Hrivnak 2013-08-07 01:30:46 UTC

This was an interesting find, but it is not a bug in pulp. The remote server seems to be actively refusing connections when a client (like pulp) makes too many connections. By default, pulp will download with 5 concurrent connections.

I can demonstrate without using pulp that the remote server refuses new connections when it sees too many connections from a host. First run this crazy command to generate a text file of links to the same XML files pulp is failing to download:

$ curl http://mirror.cc.vt.edu/pub/fedora/linux/updates/19/x86_64/repodata/repomd.xml -s| grep href| grep xml.gz | perl -pe 's|.*?href="(.*?)".*$|http://mirror.cc.vt.edu/pub/fedora/linux/updates/19/x86_64/\1|' > links.txt

Now run the following command, which tries downloading them 5 at a time using the "curl" command:

$ xargs -a links.txt -P 5 -n 1 curl -o /dev/null -4 -s -w '%{response_code}\n'

You will see several response codes of "000", which indicates a connection failure. Adjusting down to either 1 or 2 at a time seems to work without any errors. You can try this by adjusting the value for -P:

$ xargs -a links.txt -P 2 -n 1 curl -o /dev/null -4 -s -w '%{response_code}\n'

You should now see all "200" response codes.

The remote server may be throttling how many connections can be made in rapid succession, or perhaps how many connections can exist period. In any case, the solution here is to use pulp's "--max-downloads" option on this repository and set the limit to 1 or 2.