From e503fbd9412d94be43962af3b3ef7067d7f7f49b Mon Sep 17 00:00:00 2001 From: Tim Burke Date: Thu, 25 Jan 2018 17:34:39 -0800 Subject: [PATCH] Only include response body if there's a response When handling timeouts talking to the keystone server, you may see log messages like authtoken: Bad response code while validating token: 408 authtoken: Token validation failure. AttributeError: 'NoneType' object has no attribute 'text' Since there's no response from the server when keystoneclient raises RequestTimeout [1], the `response` attribute is understandably None. Now, only log the response text if there's text to log. Additionally, log the response message (as well as status code) to provide as much context as we can for the error. [1] https://github.com/openstack/python-keystoneclient/blob/3.15.0/keystoneclient/session.py#L469 Change-Id: Id400e4c38d07cbe7e1866dd572a17fc54c31e82a --- keystonemiddleware/auth_token/_identity.py | 7 ++++--- .../auth_token/test_auth_token_middleware.py | 19 +++++++++++++++++++ 2 files changed, 23 insertions(+), 3 deletions(-) diff --git a/keystonemiddleware/auth_token/_identity.py b/keystonemiddleware/auth_token/_identity.py index b7f2effe..c07eb45d 100644 --- a/keystonemiddleware/auth_token/_identity.py +++ b/keystonemiddleware/auth_token/_identity.py @@ -234,9 +234,10 @@ class IdentityServer(object): raise ksm_exceptions.ServiceError(msg) except ksa_exceptions.HttpError as e: self._LOG.error( - 'Bad response code while validating token: %s', - e.http_status) - self._LOG.warning('Identity response: %s', e.response.text) + 'Bad response code while validating token: %s %s', + e.http_status, e.message) + if hasattr(e.response, 'text'): + self._LOG.warning('Identity response: %s', e.response.text) msg = _('Failed to fetch token data from identity server') raise ksm_exceptions.ServiceError(msg) else: diff --git a/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py b/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py index efcd7efd..cf8da26b 100644 --- a/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py +++ b/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py @@ -98,6 +98,7 @@ VERSION_LIST_v3 = fixture.DiscoveryList(href=BASE_URI) VERSION_LIST_v2 = fixture.DiscoveryList(v3=False, href=BASE_URI) ERROR_TOKEN = '7ae290c2a06244c4b41692eb4e9225f2' +TIMEOUT_TOKEN = '4ed1c5e53beee59458adcf8261a8cae2' def cleanup_revoked_file(filename): @@ -1083,6 +1084,12 @@ class CommonAuthTokenMiddlewareTest(object): self.assertEqual(mock_obj.call_count, times_retry) + def test_request_timeout(self): + self.call_middleware(headers={'X-Auth-Token': TIMEOUT_TOKEN}, + expected_status=503) + self.assertIsNone(self._get_cached_token(TIMEOUT_TOKEN)) + self.assert_valid_last_url(TIMEOUT_TOKEN) + def test_nocatalog(self): conf = { 'include_service_catalog': 'False' @@ -1545,6 +1552,11 @@ def network_error_response(request, context): raise ksa_exceptions.ConnectFailure("Network connection refused.") +def request_timeout_response(request, context): + raise ksa_exceptions.RequestTimeout( + "Request to https://host/token/path timed out") + + class v2AuthTokenMiddlewareTest(BaseAuthTokenMiddlewareTest, CommonAuthTokenMiddlewareTest, testresources.ResourcedTestCase): @@ -1618,6 +1630,9 @@ class v2AuthTokenMiddlewareTest(BaseAuthTokenMiddlewareTest, url = '%s/v2.0/tokens/%s' % (BASE_URI, ERROR_TOKEN) self.requests_mock.get(url, text=network_error_response) + url = '%s/v2.0/tokens/%s' % (BASE_URI, TIMEOUT_TOKEN) + self.requests_mock.get(url, text=request_timeout_response) + self.set_middleware() def assert_unscoped_default_tenant_auto_scopes(self, token): @@ -1824,6 +1839,8 @@ class v3AuthTokenMiddlewareTest(BaseAuthTokenMiddlewareTest, if token_id == ERROR_TOKEN: msg = "Network connection refused." raise ksa_exceptions.ConnectFailure(msg) + elif token_id == TIMEOUT_TOKEN: + request_timeout_response(request, context) try: response = self.examples.JSON_TOKEN_RESPONSES[token_id] @@ -2372,6 +2389,8 @@ class v3CompositeAuthTests(BaseAuthTokenMiddlewareTest, if token_id == ERROR_TOKEN: msg = "Network connection refused." raise ksc_exceptions.ConnectionRefused(msg) + elif token_id == TIMEOUT_TOKEN: + request_timeout_response(request, context) try: response = self.examples.JSON_TOKEN_RESPONSES[token_id]