import os
import re
import socket
+import ssl
import sys
import time
import types
def _intercept_http_request(self, uri, method="GET", headers={}, **kwargs):
- if (self.max_request_size and
- kwargs.get('body') and
- self.max_request_size < len(kwargs['body'])):
- raise apiclient_errors.MediaUploadSizeError("Request size %i bytes exceeds published limit of %i bytes" % (len(kwargs['body']), self.max_request_size))
-
- if config.get("ARVADOS_EXTERNAL_CLIENT", "") == "true":
- headers['X-External-Client'] = '1'
-
- headers['Authorization'] = 'OAuth2 %s' % self.arvados_api_token
if not headers.get('X-Request-Id'):
headers['X-Request-Id'] = self._request_id()
+ try:
+ if (self.max_request_size and
+ kwargs.get('body') and
+ self.max_request_size < len(kwargs['body'])):
+ raise apiclient_errors.MediaUploadSizeError("Request size %i bytes exceeds published limit of %i bytes" % (len(kwargs['body']), self.max_request_size))
- retryable = method in [
- 'DELETE', 'GET', 'HEAD', 'OPTIONS', 'PUT']
- retry_count = self._retry_count if retryable else 0
-
- if (not retryable and
- time.time() - self._last_request_time > self._max_keepalive_idle):
- # High probability of failure due to connection atrophy. Make
- # sure this request [re]opens a new connection by closing and
- # forgetting all cached connections first.
- for conn in self.connections.values():
- conn.close()
- self.connections.clear()
-
- delay = self._retry_delay_initial
- for _ in range(retry_count):
- self._last_request_time = time.time()
- try:
- return self.orig_http_request(uri, method, headers=headers, **kwargs)
- except http.client.HTTPException:
- _logger.debug("Retrying API request in %d s after HTTP error",
- delay, exc_info=True)
- except socket.error:
- # This is the one case where httplib2 doesn't close the
- # underlying connection first. Close all open
- # connections, expecting this object only has the one
- # connection to the API server. This is safe because
- # httplib2 reopens connections when needed.
- _logger.debug("Retrying API request in %d s after socket error",
- delay, exc_info=True)
+ if config.get("ARVADOS_EXTERNAL_CLIENT", "") == "true":
+ headers['X-External-Client'] = '1'
+
+ headers['Authorization'] = 'OAuth2 %s' % self.arvados_api_token
+
+ retryable = method in [
+ 'DELETE', 'GET', 'HEAD', 'OPTIONS', 'PUT']
+ retry_count = self._retry_count if retryable else 0
+
+ if (not retryable and
+ time.time() - self._last_request_time > self._max_keepalive_idle):
+ # High probability of failure due to connection atrophy. Make
+ # sure this request [re]opens a new connection by closing and
+ # forgetting all cached connections first.
for conn in self.connections.values():
conn.close()
- except httplib2.SSLHandshakeError as e:
- # Intercept and re-raise with a better error message.
- raise httplib2.SSLHandshakeError("Could not connect to %s\n%s\nPossible causes: remote SSL/TLS certificate expired, or was issued by an untrusted certificate authority." % (uri, e))
+ self.connections.clear()
+
+ delay = self._retry_delay_initial
+ for _ in range(retry_count):
+ self._last_request_time = time.time()
+ try:
+ return self.orig_http_request(uri, method, headers=headers, **kwargs)
+ except http.client.HTTPException:
+ _logger.debug("[%s] Retrying API request in %d s after HTTP error",
+ headers['X-Request-Id'], delay, exc_info=True)
+ except ssl.SSLCertVerificationError as e:
+ raise ssl.SSLCertVerificationError(e.args[0], "Could not connect to %s\n%s\nPossible causes: remote SSL/TLS certificate expired, or was issued by an untrusted certificate authority." % (uri, e)) from None
+ except socket.error:
+ # This is the one case where httplib2 doesn't close the
+ # underlying connection first. Close all open
+ # connections, expecting this object only has the one
+ # connection to the API server. This is safe because
+ # httplib2 reopens connections when needed.
+ _logger.debug("[%s] Retrying API request in %d s after socket error",
+ headers['X-Request-Id'], delay, exc_info=True)
+ for conn in self.connections.values():
+ conn.close()
+
+ time.sleep(delay)
+ delay = delay * self._retry_delay_backoff
- time.sleep(delay)
- delay = delay * self._retry_delay_backoff
-
- self._last_request_time = time.time()
- return self.orig_http_request(uri, method, headers=headers, **kwargs)
+ self._last_request_time = time.time()
+ return self.orig_http_request(uri, method, headers=headers, **kwargs)
+ except Exception as e:
+ # Prepend "[request_id] " to the error message, which we
+ # assume is the first string argument passed to the exception
+ # constructor.
+ for i in range(len(e.args or ())):
+ if type(e.args[i]) == type(""):
+ e.args = e.args[:i] + ("[{}] {}".format(headers['X-Request-Id'], e.args[i]),) + e.args[i+1:]
+ raise type(e)(*e.args)
+ raise
def _patch_http_request(http, api_token):
http.arvados_api_token = api_token
self.get_counter.add(1)
+ request_id = (request_id or
+ (hasattr(self, 'api_client') and self.api_client.request_id) or
+ arvados.util.new_request_id())
+ if headers is None:
+ headers = {}
+ headers['X-Request-Id'] = request_id
+
slot = None
blob = None
try:
self.misses_counter.add(1)
- if headers is None:
- headers = {}
- headers['X-Request-Id'] = (request_id or
- (hasattr(self, 'api_client') and self.api_client.request_id) or
- arvados.util.new_request_id())
-
# If the locator has hints specifying a prefix (indicating a
# remote keepproxy) or the UUID of a local gateway service,
# read data from the indicated service(s) instead of the usual
for key in sorted_roots)
if not roots_map:
raise arvados.errors.KeepReadError(
- "failed to read {}: no Keep services available ({})".format(
- loc_s, loop.last_result()))
+ "[{}] failed to read {}: no Keep services available ({})".format(
+ request_id, loc_s, loop.last_result()))
elif not_founds == len(sorted_roots):
raise arvados.errors.NotFoundError(
- "{} not found".format(loc_s), service_errors)
+ "[{}] {} not found".format(request_id, loc_s), service_errors)
else:
raise arvados.errors.KeepReadError(
- "failed to read {} after {}".format(loc_s, loop.attempts_str()), service_errors, label="service")
+ "[{}] failed to read {} after {}".format(request_id, loc_s, loop.attempts_str()), service_errors, label="service")
@retry.retry_method
def put(self, data, copies=2, num_retries=None, request_id=None, classes=None):
return loc_s
locator = KeepLocator(loc_s)
+ request_id = (request_id or
+ (hasattr(self, 'api_client') and self.api_client.request_id) or
+ arvados.util.new_request_id())
headers = {
- 'X-Request-Id': (request_id or
- (hasattr(self, 'api_client') and self.api_client.request_id) or
- arvados.util.new_request_id()),
+ 'X-Request-Id': request_id,
'X-Keep-Desired-Replicas': str(copies),
}
roots_map = {}
return writer_pool.response()
if not roots_map:
raise arvados.errors.KeepWriteError(
- "failed to write {}: no Keep services available ({})".format(
- data_hash, loop.last_result()))
+ "[{}] failed to write {}: no Keep services available ({})".format(
+ request_id, data_hash, loop.last_result()))
else:
service_errors = ((key, roots_map[key].last_result()['error'])
for key in sorted_roots
if roots_map[key].last_result()['error'])
raise arvados.errors.KeepWriteError(
- "failed to write {} after {} (wanted {} copies but wrote {})".format(
- data_hash, loop.attempts_str(), (copies, classes), writer_pool.done()), service_errors, label="service")
+ "[{}] failed to write {} after {} (wanted {} copies but wrote {})".format(
+ request_id, data_hash, loop.attempts_str(), (copies, classes), writer_pool.done()), service_errors, label="service")
def local_store_put(self, data, copies=1, num_retries=None, classes=[]):
"""A stub for put().
for msg in ["Bad UUID format", "Bad output format"]:
self.assertIn(msg, err_s)
+ @mock.patch('time.sleep')
+ def test_exceptions_include_request_id(self, sleep):
+ api = arvados.api('v1')
+ api.request_id='fake-request-id'
+ api._http.orig_http_request = mock.MagicMock()
+ api._http.orig_http_request.side_effect = socket.error('mock error')
+ caught = None
+ try:
+ api.users().current().execute()
+ except Exception as e:
+ caught = e
+ self.assertRegex(str(caught), r'fake-request-id')
+
def test_exceptions_without_errors_have_basic_info(self):
mock_responses = {
'arvados.humans.delete': (
self.keep_client.head(self.locator)
self.assertAutomaticRequestId(mock.responses[0])
+ def test_request_id_in_exception(self):
+ with tutil.mock_keep_responses(b'', 400, 400, 400) as mock:
+ with self.assertRaisesRegex(arvados.errors.KeepReadError, self.test_id):
+ self.keep_client.head(self.locator, request_id=self.test_id)
+
+ with tutil.mock_keep_responses(b'', 400, 400, 400) as mock:
+ with self.assertRaisesRegex(arvados.errors.KeepReadError, r'req-[a-z0-9]{20}'):
+ self.keep_client.get(self.locator)
+
+ with tutil.mock_keep_responses(b'', 400, 400, 400) as mock:
+ with self.assertRaisesRegex(arvados.errors.KeepWriteError, self.test_id):
+ self.keep_client.put(self.data, request_id=self.test_id)
+
+ with tutil.mock_keep_responses(b'', 400, 400, 400) as mock:
+ with self.assertRaisesRegex(arvados.errors.KeepWriteError, r'req-[a-z0-9]{20}'):
+ self.keep_client.put(self.data)
+
def assertAutomaticRequestId(self, resp):
hdr = [x for x in resp.getopt(pycurl.HTTPHEADER)
if x.startswith('X-Request-Id: ')][0]