From 7074ee23b54c6fa7ef5c4102b31ca8e89186ffae Mon Sep 17 00:00:00 2001
From: Jamie Lennox <jamielennox@redhat.com>
Date: Thu, 16 Apr 2015 14:21:29 +1000
Subject: [PATCH] Remove the _msg_format function

The _msg_format plugin was just a way to print out the debug statement
from environment variables. We can do this directly from the user plugin
rather than using env.

Change-Id: I1a8a6a71fcd23eb3da26079264e119a3c29bcb07
---
 keystonemiddleware/auth_token/__init__.py     | 13 ++-----------
 keystonemiddleware/auth_token/_user_plugin.py | 19 +++++++++++++++++++
 .../auth_token/test_auth_token_middleware.py  | 19 +++++++++++++------
 3 files changed, 34 insertions(+), 17 deletions(-)

diff --git a/keystonemiddleware/auth_token/__init__.py b/keystonemiddleware/auth_token/__init__.py
index e680a0c8..3a3e0feb 100644
--- a/keystonemiddleware/auth_token/__init__.py
+++ b/keystonemiddleware/auth_token/__init__.py
@@ -535,16 +535,6 @@ class AuthProtocol(object):
         we can't authenticate.
 
         """
-        def _fmt_msg(env):
-            msg = ('user: user_id %s, project_id %s, roles %s '
-                   'service: user_id %s, project_id %s, roles %s' % (
-                       env.get('HTTP_X_USER_ID'), env.get('HTTP_X_PROJECT_ID'),
-                       env.get('HTTP_X_ROLES'),
-                       env.get('HTTP_X_SERVICE_USER_ID'),
-                       env.get('HTTP_X_SERVICE_PROJECT_ID'),
-                       env.get('HTTP_X_SERVICE_ROLES')))
-            return msg
-
         self._token_cache.initialize(request.environ)
         self._remove_auth_headers(request.environ)
 
@@ -601,7 +591,8 @@ class AuthProtocol(object):
             self._LOG.critical(_LC('Unable to obtain admin token: %s'), e)
             raise webob.exc.HTTPServiceUnavailable()
 
-        self._LOG.debug("Received request from %s", _fmt_msg(request.environ))
+        if self._LOG.isEnabledFor(logging.DEBUG):
+            self._LOG.debug('Received request from %s' % p._log_format)
 
         response = request.get_response(self._app)
 
diff --git a/keystonemiddleware/auth_token/_user_plugin.py b/keystonemiddleware/auth_token/_user_plugin.py
index 12a8767c..9bdc400c 100644
--- a/keystonemiddleware/auth_token/_user_plugin.py
+++ b/keystonemiddleware/auth_token/_user_plugin.py
@@ -105,6 +105,13 @@ class _TokenData(object):
         """
         return frozenset(self._stored_auth_ref.role_names or [])
 
+    @property
+    def _log_format(self):
+        roles = ','.join(self.role_names)
+        return 'user_id %s, project_id %s, roles %s' % (self.user_id,
+                                                        self.project_id,
+                                                        roles)
+
 
 class UserAuthPlugin(base_identity.BaseIdentityPlugin):
     """The incoming authentication credentials.
@@ -167,3 +174,15 @@ class UserAuthPlugin(base_identity.BaseIdentityPlugin):
         # calculated by the middleware. reauthenticate=False in __init__ should
         # ensure that this function is only called on the first access.
         return self._user_auth_ref
+
+    @property
+    def _log_format(self):
+        msg = []
+
+        if self.has_user_token:
+            msg.append('user: %s' % self.user._log_format)
+
+        if self.has_service_token:
+            msg.append('service: %s' % self.service._log_format)
+
+        return ' '.join(msg)
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 c6372784..c1a77a0d 100644
--- a/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py
+++ b/keystonemiddleware/tests/unit/auth_token/test_auth_token_middleware.py
@@ -1978,14 +1978,21 @@ class CommonCompositeAuthTests(object):
         self.assertEqual(FakeApp.SUCCESS, resp.body)
         expected_env = dict(EXPECTED_V2_DEFAULT_ENV_RESPONSE)
         expected_env.update(EXPECTED_V2_DEFAULT_SERVICE_ENV_RESPONSE)
-        self.assertIn('Received request from user: '
-                      'user_id %(HTTP_X_USER_ID)s, '
+
+        # role list may get reordered, check for string pieces individually
+        self.assertIn('Received request from user: ', fake_logger.output)
+        self.assertIn('user_id %(HTTP_X_USER_ID)s, '
                       'project_id %(HTTP_X_TENANT_ID)s, '
-                      'roles %(HTTP_X_ROLES)s '
-                      'service: user_id %(HTTP_X_SERVICE_USER_ID)s, '
+                      'roles ' % expected_env, fake_logger.output)
+        self.assertIn('service: user_id %(HTTP_X_SERVICE_USER_ID)s, '
                       'project_id %(HTTP_X_SERVICE_PROJECT_ID)s, '
-                      'roles %(HTTP_X_SERVICE_ROLES)s' % expected_env,
-                      fake_logger.output)
+                      'roles ' % expected_env, fake_logger.output)
+
+        roles = ','.join([expected_env['HTTP_X_SERVICE_ROLES'],
+                          expected_env['HTTP_X_ROLES']])
+
+        for r in roles.split(','):
+            self.assertIn(r, fake_logger.output)
 
     def test_composite_auth_invalid_service_token(self):
         token = self.token_dict['uuid_token_default']