diff --git a/Changelog.rst b/Changelog.rst index 4b5cc3ca..d573cff3 100644 --- a/Changelog.rst +++ b/Changelog.rst @@ -10,6 +10,9 @@ Version compatible with elasticsearch 5.0 * when using SSL certificate validation is now on by default. Install ``certifi`` or supply root certificate bundle. + * ``elasticsearch.trace`` logger now also logs failed requests, signature of + internal logging method ``log_request_fail`` has changed, all custom + connection classes need to be updated * added ``headers`` arg to connections to support custom http headers * passing in a keyword parameter with ``None`` as value will cause that param to be ignored diff --git a/elasticsearch/connection/base.py b/elasticsearch/connection/base.py index 9cad0ff4..c0206b2e 100644 --- a/elasticsearch/connection/base.py +++ b/elasticsearch/connection/base.py @@ -45,16 +45,30 @@ class Connection(object): def __repr__(self): return '<%s: %s>' % (self.__class__.__name__, self.host) + def _pretty_json(self, data): + # pretty JSON in tracer curl logs + try: + return json.dumps(json.loads(data), sort_keys=True, indent=2, separators=(',', ': ')).replace("'", r'\u0027') + except (ValueError, TypeError): + # non-json data or a bulk request + return data + + def _log_trace(self, method, path, body, status_code, response, duration): + if not tracer.isEnabledFor(logging.INFO) or not tracer.handlers: + return + + # include pretty in trace curls + path = path.replace('?', '?pretty&', 1) if '?' in path else path + '?pretty' + if self.url_prefix: + path = path.replace(self.url_prefix, '', 1) + tracer.info("curl -X%s 'http://localhost:9200%s' -d '%s'", method, path, self._pretty_json(body) if body else '') + + if tracer.isEnabledFor(logging.DEBUG): + tracer.debug('#[%s] (%.3fs)\n#%s', status_code, duration, self._pretty_json(response).replace('\n', '\n#') if response else '') + def log_request_success(self, method, full_url, path, body, status_code, response, duration): """ Log a successful API call. """ # TODO: optionally pass in params instead of full_url and do urlencode only when needed - def _pretty_json(data): - # pretty JSON in tracer curl logs - try: - return json.dumps(json.loads(data), sort_keys=True, indent=2, separators=(',', ': ')).replace("'", r'\u0027') - except (ValueError, TypeError): - # non-json data or a bulk request - return data # body has already been serialized to utf-8, deserialize it for logging # TODO: find a better way to avoid (de)encoding the body back and forth @@ -68,17 +82,9 @@ class Connection(object): logger.debug('> %s', body) logger.debug('< %s', response) - if tracer.isEnabledFor(logging.INFO) and tracer.handlers: - # include pretty in trace curls - path = path.replace('?', '?pretty&', 1) if '?' in path else path + '?pretty' - if self.url_prefix: - path = path.replace(self.url_prefix, '', 1) - tracer.info("curl -X%s 'http://localhost:9200%s' -d '%s'", method, path, _pretty_json(body) if body else '') + self._log_trace(method, path, body, status_code, response, duration) - if tracer.isEnabledFor(logging.DEBUG): - tracer.debug('#[%s] (%.3fs)\n#%s', status_code, duration, _pretty_json(response).replace('\n', '\n#') if response else '') - - def log_request_fail(self, method, full_url, body, duration, status_code=None, response=None, exception=None): + def log_request_fail(self, method, full_url, path, body, duration, status_code=None, response=None, exception=None): """ Log an unsuccessful API call. """ # do not log 404s on HEAD requests if method == 'HEAD' and status_code == 404: @@ -95,6 +101,8 @@ class Connection(object): logger.debug('> %s', body) + self._log_trace(method, path, body, status_code, response, duration) + if response is not None: logger.debug('< %s', response) diff --git a/elasticsearch/connection/http_requests.py b/elasticsearch/connection/http_requests.py index 895888ab..6c9a924b 100644 --- a/elasticsearch/connection/http_requests.py +++ b/elasticsearch/connection/http_requests.py @@ -71,18 +71,18 @@ class RequestsHttpConnection(Connection): duration = time.time() - start raw_data = response.text except requests.exceptions.SSLError as e: - self.log_request_fail(method, url, body, time.time() - start, exception=e) + self.log_request_fail(method, url, response.request.path_url, body, time.time() - start, exception=e) raise SSLError('N/A', str(e), e) except requests.Timeout as e: - self.log_request_fail(method, url, body, time.time() - start, exception=e) + self.log_request_fail(method, url, response.request.path_url, body, time.time() - start, exception=e) raise ConnectionTimeout('TIMEOUT', str(e), e) except requests.ConnectionError as e: - self.log_request_fail(method, url, body, time.time() - start, exception=e) + self.log_request_fail(method, url, response.request.path_url, body, time.time() - start, exception=e) raise ConnectionError('N/A', str(e), e) # raise errors based on http status codes, let the client handle those if needed if not (200 <= response.status_code < 300) and response.status_code not in ignore: - self.log_request_fail(method, url, body, duration, response.status_code, raw_data) + self.log_request_fail(method, url, response.request.path_url, body, duration, response.status_code, raw_data) self._raise_error(response.status_code, raw_data) self.log_request_success(method, url, response.request.path_url, body, response.status_code, raw_data, duration) diff --git a/elasticsearch/connection/http_urllib3.py b/elasticsearch/connection/http_urllib3.py index 0f836e23..066466cd 100644 --- a/elasticsearch/connection/http_urllib3.py +++ b/elasticsearch/connection/http_urllib3.py @@ -110,17 +110,17 @@ class Urllib3HttpConnection(Connection): duration = time.time() - start raw_data = response.data.decode('utf-8') except UrllibSSLError as e: - self.log_request_fail(method, full_url, body, time.time() - start, exception=e) + self.log_request_fail(method, full_url, url, body, time.time() - start, exception=e) raise SSLError('N/A', str(e), e) except ReadTimeoutError as e: - self.log_request_fail(method, full_url, body, time.time() - start, exception=e) + self.log_request_fail(method, full_url, url, body, time.time() - start, exception=e) raise ConnectionTimeout('TIMEOUT', str(e), e) except Exception as e: - self.log_request_fail(method, full_url, body, time.time() - start, exception=e) + self.log_request_fail(method, full_url, url, body, time.time() - start, exception=e) raise ConnectionError('N/A', str(e), e) if not (200 <= response.status < 300) and response.status not in ignore: - self.log_request_fail(method, url, body, duration, response.status, raw_data) + self.log_request_fail(method, full_url, url, body, duration, response.status, raw_data) self._raise_error(response.status, raw_data) self.log_request_success(method, full_url, url, body, response.status, diff --git a/test_elasticsearch/test_connection.py b/test_elasticsearch/test_connection.py index c5cc5e7f..540623e1 100644 --- a/test_elasticsearch/test_connection.py +++ b/test_elasticsearch/test_connection.py @@ -138,10 +138,10 @@ class TestRequestsConnection(TestCase): con = self._get_mock_connection(response_body='{"answer": 42}', status_code=500) self.assertRaises(TransportError, con.perform_request, 'GET', '/', {'param': 42}, '{}'.encode('utf-8')) - # no trace request - self.assertEquals(0, tracer.info.call_count) - # no trace response - self.assertEquals(0, tracer.debug.call_count) + # trace request + self.assertEquals(1, tracer.info.call_count) + # trace response + self.assertEquals(1, tracer.debug.call_count) # log url and duration self.assertEquals(1, logger.warning.call_count) self.assertTrue(re.match(