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.
  <traceback>
  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

2 files changed, 23 insertions, 3 deletions

diff --git a/keystonemiddleware/auth_token/_identity.py b/keystonemiddleware/auth_token/_identity.py
index b7f2eff..c07eb45 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 efcd7ef..cf8da26 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]