Project

Profile

Help

Issue #2941

closed

download failure produces long traceback

Added by dkliban@redhat.com almost 7 years ago. Updated almost 5 years ago.

Status:
CLOSED - WONTFIX
Priority:
Normal
Assignee:
-
Category:
-
Sprint/Milestone:
Start date:
Due date:
Estimated time:
Severity:
2. Medium
Version:
Platform Release:
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Sprint:
Quarter:

Description

My DNS was temporarily not working. When I went to sync a file repo I got the following in my logs. We should probably handle these failures more gracefully.

Also notice the pickling problem on the last line of the traceback.

Jul 24 15:14:28 dev.example.com celery[19624]: [2017-07-24 15:14:28,784: WARNING/PoolWorker-1] FileImporter: synchronizing repository test-repo
Jul 24 15:14:31 dev.example.com celery[19624]: [2017-07-24 15:14:31,571: ERROR/PoolWorker-1] Repair failed: HttpDownload: id=4344 url=https://repos.fedorapeople.org/pulp/pulp/fixtures/file/PULP_MANIFEST writer=P
ULP_MANIFEST | repair: retries=1 | timeout: connect=10 read=30 | ssl: validation=False CA= key= certificate= | User: name= password= | proxy= headers={}
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connection.py", line 141, in _new_conn
Jul 24 15:14:31 dev.example.com celery[19624]:     (self.host, self.port), self.timeout, **extra_kw)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/util/connection.py", line 60, in create_connection
Jul 24 15:14:31 dev.example.com celery[19624]:     for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/usr/lib64/python3.5/socket.py", line 733, in getaddrinfo
Jul 24 15:14:31 dev.example.com celery[19624]:     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
Jul 24 15:14:31 dev.example.com celery[19624]: socket.gaierror: [Errno -2] Name or service not known
Jul 24 15:14:31 dev.example.com celery[19624]: During handling of the above exception, another exception occurred:
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connectionpool.py", line 600, in urlopen
Jul 24 15:14:31 dev.example.com celery[19624]:     chunked=chunked)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connectionpool.py", line 345, in _make_request
Jul 24 15:14:31 dev.example.com celery[19624]:     self._validate_conn(conn)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connectionpool.py", line 844, in _validate_conn
Jul 24 15:14:31 dev.example.com celery[19624]:     conn.connect()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connection.py", line 284, in connect
Jul 24 15:14:31 dev.example.com celery[19624]:     conn = self._new_conn()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connection.py", line 150, in _new_conn
Jul 24 15:14:31 dev.example.com celery[19624]:     self, "Failed to establish a new connection: %s" % e)
Jul 24 15:14:31 dev.example.com celery[19624]: urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name 
or service not known
Jul 24 15:14:31 dev.example.com celery[19624]: During handling of the above exception, another exception occurred:
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/requests/adapters.py", line 440, in send
Jul 24 15:14:31 dev.example.com celery[19624]:     timeout=timeout
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/connectionpool.py", line 649, in urlopen
Jul 24 15:14:31 dev.example.com celery[19624]:     _stacktrace=sys.exc_info()[2])
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/urllib3/util/retry.py", line 388, in increment
Jul 24 15:14:31 dev.example.com celery[19624]:     raise MaxRetryError(_pool, url, error or ResponseError(cause))
Jul 24 15:14:31 dev.example.com celery[19624]: urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='repos.fedorapeople.org', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFES
T (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known',))
Jul 24 15:14:31 dev.example.com celery[19624]: During handling of the above exception, another exception occurred:
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/http.py", line 214, in _send
Jul 24 15:14:31 dev.example.com celery[19624]:     self.reply = self.method()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/http.py", line 192, in _get
Jul 24 15:14:31 dev.example.com celery[19624]:     return self.session.get(self.url, **self._settings())
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/requests/sessions.py", line 515, in get
Jul 24 15:14:31 dev.example.com celery[19624]:     return self.request('GET', url, **kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/requests/sessions.py", line 502, in request
Jul 24 15:14:31 dev.example.com celery[19624]:     resp = self.send(prep, **send_kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/requests/sessions.py", line 612, in send
Jul 24 15:14:31 dev.example.com celery[19624]:     r = adapter.send(request, **kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/requests/adapters.py", line 504, in send
Jul 24 15:14:31 dev.example.com celery[19624]:     raise ConnectionError(e, request=request)
Jul 24 15:14:31 dev.example.com celery[19624]: requests.exceptions.ConnectionError: HTTPSConnectionPool(host='repos.fedorapeople.org', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANI
FEST (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known',))
Jul 24 15:14:31 dev.example.com celery[19624]: During handling of the above exception, another exception occurred:
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 154, in _repair
Jul 24 15:14:31 dev.example.com celery[19624]:     raise error
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 261, in __call__
Jul 24 15:14:31 dev.example.com celery[19624]:     self._attempt()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 182, in _attempt
Jul 24 15:14:31 dev.example.com celery[19624]:     self._send()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/http.py", line 222, in _send
Jul 24 15:14:31 dev.example.com celery[19624]:     raise DownloadFailed(self, str(error))
Jul 24 15:14:31 dev.example.com celery[19624]: pulpcore.download.error.DownloadFailed: HttpDownload: id=4344 url=https://repos.fedorapeople.org/pulp/pulp/fixtures/file/PULP_MANIFEST writer=PULP_MANIFEST | repair
: retries=1 | timeout: connect=10 read=30 | ssl: validation=False CA= key= certificate= | User: name= password= | proxy= headers={} - Failed. Reason: HTTPSConnectionPool(host='repos.fedorapeople.org', port=443):
 Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFEST (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known',))
Jul 24 15:14:31 dev.example.com celery[19624]: [2017-07-24 15:14:31,574: ERROR/PoolWorker-1] Task failed : [40a91f7e-24b0-47e0-82f2-f0342a4144f1]
Jul 24 15:14:31 dev.example.com celery[19624]: [2017-07-24 15:14:31,594: ERROR/PoolWorker-1] Task pulpcore.app.tasks.importer.sync[40a91f7e-24b0-47e0-82f2-f0342a4144f1] raised unexpected: DownloadFailed('<pulpcore.download.http.HttpDownload object at 0x7fa21a7943d8>', "HTTPSConnectionPool(host='repos.fedorapeople.org', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFEST (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known',))")
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/celery/app/trace.py", line 367, in trace_task
Jul 24 15:14:31 dev.example.com celery[19624]:     R = retval = fun(*args, **kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/tasking/tasks.py", line 272, in __call__
Jul 24 15:14:31 dev.example.com celery[19624]:     return super(UserFacingTask, self).__call__(*args, **kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/celery/app/trace.py", line 622, in __protected_call__
Jul 24 15:14:31 dev.example.com celery[19624]:     return self.run(*args, **kwargs)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/app/tasks/importer.py", line 75, in sync
Jul 24 15:14:31 dev.example.com celery[19624]:     importer.sync()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp_file/pulp_file/app/models.py", line 85, in sync
Jul 24 15:14:31 dev.example.com celery[19624]:     changeset = self._build_changeset()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp_file/pulp_file/app/models.py", line 233, in _build_changeset
Jul 24 15:14:31 dev.example.com celery[19624]:     manifest = self._fetch_manifest()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp_file/pulp_file/app/models.py", line 133, in _fetch_manifest
Jul 24 15:14:31 dev.example.com celery[19624]:     download()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 263, in __call__
Jul 24 15:14:31 dev.example.com celery[19624]:     self._repair(error)
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 158, in _repair
Jul 24 15:14:31 dev.example.com celery[19624]:     raise error
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 154, in _repair
Jul 24 15:14:31 dev.example.com celery[19624]:     raise error
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 261, in __call__
Jul 24 15:14:31 dev.example.com celery[19624]:     self._attempt()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/single.py", line 182, in _attempt
Jul 24 15:14:31 dev.example.com celery[19624]:     self._send()
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/devel/pulp/platform/pulpcore/download/http.py", line 222, in _send
Jul 24 15:14:31 dev.example.com celery[19624]:     raise DownloadFailed(self, str(error))
Jul 24 15:14:31 dev.example.com celery[19624]: pulpcore.download.error.DownloadFailed: ('<pulpcore.download.http.HttpDownload object at 0x7fa21a7943d8>', "HTTPSConnectionPool(host='repos.fedorapeople.org', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFEST (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known',))")
Jul 24 15:14:31 dev.example.com celery[19624]: [2017-07-24 15:14:31,597: ERROR/MainProcess] Task handler raised error: <MaybeEncodingError: Error sending result: ''(1, <ExceptionInfo: DownloadFailed(\'<pulpcore.download.http.HttpDownload object at 0x7fa21a7943d8>\', "HTTPSConnectionPool(host=\'repos.fedorapeople.org\', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFEST (Caused by NewConnectionError(\'<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known\',))")>, None)''. Reason: ''PicklingError("Can\'t pickle <class \'pulpcore.download.error.DownloadFailed\'>: it\'s not the same object as pulpcore.download.error.DownloadFailed",)''.>
Jul 24 15:14:31 dev.example.com celery[19624]: Traceback (most recent call last):
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/billiard/pool.py", line 363, in workloop
Jul 24 15:14:31 dev.example.com celery[19624]:     put((READY, (job, i, result, inqW_fd)))
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/billiard/queues.py", line 366, in put
Jul 24 15:14:31 dev.example.com celery[19624]:     self.send_payload(ForkingPickler.dumps(obj))
Jul 24 15:14:31 dev.example.com celery[19624]:   File "/home/vagrant/.virtualenvs/pulp/lib/python3.5/site-packages/billiard/reduction.py", line 56, in dumps
Jul 24 15:14:31 dev.example.com celery[19624]:     cls(buf, protocol).dump(obj)
Jul 24 15:14:31 dev.example.com celery[19624]: billiard.pool.MaybeEncodingError: Error sending result: ''(1, <ExceptionInfo: DownloadFailed(\'<pulpcore.download.http.HttpDownload object at 0x7fa21a7943d8>\', "HTTPSConnectionPool(host=\'repos.fedorapeople.org\', port=443): Max retries exceeded with url: /pulp/pulp/fixtures/file/PULP_MANIFEST (Caused by NewConnectionError(\'<urllib3.connection.VerifiedHTTPSConnection object at 0x7fa21a75d7b8>: Failed to establish a new connection: [Errno -2] Name or service not known\',))")>, None)''. Reason: ''PicklingError("Can\'t pickle <class \'pulpcore.download.error.DownloadFailed\'>: it\'s not the same object as pulpcore.download.error.DownloadFailed",)''.
Actions #1

Updated by mhrivnak almost 7 years ago

Agreed, we should just log the "name or service not known" error without a stack trace. The stack trace doesn't add value here.

It's also interesting to see the pickling error, which may deserve its own issue depending on what's going on there. I assume celery is trying to pickle the exception because it's not being intercepted some other way? I know it defaults to pickling a return value, but pickling an exception is interesting. In any case, it would be ideal to avoid pickle entirely with Pulp 3.

Actions #2

Updated by bmbouter over 6 years ago

The pickling is especially weird because we switched all of our usage of Celery to JSON and away from pickle. Celery must use pickle internally. I don't think it's worth the time to investigate, but I wonder if Celery4 still has this internal pickling behavior.

Actions #3

Updated by ttereshc over 6 years ago

  • Triaged changed from No to Yes
Actions #4

Updated by dalley almost 6 years ago

  • Status changed from NEW to CLOSED - WONTFIX

Since we are no longer using Celery, I will assume this bug can be closed. It can be refiled later if needed.

Actions #5

Updated by daviddavis almost 5 years ago

  • Sprint/Milestone set to 3.0.0
Actions #6

Updated by bmbouter almost 5 years ago

  • Tags deleted (Pulp 3)

Also available in: Atom PDF