Log request-id for each api call

Added new private method to log request-id of each api call
for both SessionClient and HTTPClient. Already available
ks_logger and client_logger will be used for SessionClient
and HTTPClient respectively.

Change-Id: I679c57b96071ecd9bcd1ab2ed50692195586ca52
Implements: blueprint log-request-id

cinderclient/client.py

@@ -85,6 +85,16 @@ def get_volume_api_from_url(url):
     raise exceptions.UnsupportedVersion(msg)
 
 
+def _log_request_id(logger, resp, service_name):
+    request_id = resp.headers.get('x-openstack-request-id')
+    if request_id:
+        logger.debug('%(method)s call to %(service_type)s for %(url)s '
+                     'used request id %(response_request_id)s',
+                     {'method': resp.request.method,
+                      'service_type': service_name,
+                      'url': resp.url, 'response_request_id': request_id})
+
+
 class SessionClient(adapter.LegacyJsonAdapter):
 
     def __init__(self, *args, **kwargs):
@@ -102,6 +112,11 @@ class SessionClient(adapter.LegacyJsonAdapter):
         resp, body = super(SessionClient, self).request(*args,
                                                         raise_exc=False,
                                                         **kwargs)
+
+        # if service name is None then use service_type for logging
+        service = self.service_name or self.service_type
+        _log_request_id(self.logger, resp, service)
+
         if raise_exc and resp.status_code >= 400:
             raise exceptions.from_response(resp, body)
 
@@ -162,7 +177,8 @@ class HTTPClient(object):
                  service_name=None, volume_service_name=None,
                  bypass_url=None, retries=None,
                  http_log_debug=False, cacert=None,
-                 auth_system='keystone', auth_plugin=None, api_version=None):
+                 auth_system='keystone', auth_plugin=None, api_version=None,
+                 logger=None):
         self.user = user
         self.password = password
         self.projectid = projectid
@@ -205,7 +221,7 @@ class HTTPClient(object):
         self.auth_system = auth_system
         self.auth_plugin = auth_plugin
 
-        self._logger = logging.getLogger(__name__)
+        self._logger = logger or logging.getLogger(__name__)
 
     def _safe_header(self, name, value):
         if name in HTTPClient.SENSITIVE_HEADERS:
@@ -250,6 +266,10 @@ class HTTPClient(object):
             resp.headers,
             resp.text)
 
+        # if service name is None then use service_type for logging
+        service = self.service_name or self.service_type
+        _log_request_id(self._logger, resp, service)
+
     def request(self, url, method, **kwargs):
         kwargs.setdefault('headers', kwargs.get('headers', {}))
         kwargs['headers']['User-Agent'] = self.USER_AGENT
@@ -561,6 +581,7 @@ def _construct_http_client(username=None, password=None, project_id=None,
     else:
         # FIXME(jamielennox): username and password are now optional. Need
         # to test that they were provided in this mode.
+        logger = kwargs.get('logger')
         return HTTPClient(username,
                           password,
                           projectid=project_id,
@@ -581,6 +602,7 @@ def _construct_http_client(username=None, password=None, project_id=None,
                           cacert=cacert,
                           auth_system=auth_system,
                           auth_plugin=auth_plugin,
+                          logger=logger
                           )
 
 

cinderclient/shell.py

@@ -107,6 +107,10 @@ class CinderClientArgumentParser(argparse.ArgumentParser):
 
 class OpenStackCinderShell(object):
 
+    def __init__(self):
+        self.ks_logger = None
+        self.client_logger = None
+
     def get_base_parser(self):
         parser = CinderClientArgumentParser(
             prog='cinder',
@@ -455,15 +459,16 @@ class OpenStackCinderShell(object):
         logger.setLevel(logging.WARNING)
         logger.addHandler(streamhandler)
 
-        client_logger = logging.getLogger(client.__name__)
+        self.client_logger = logging.getLogger(client.__name__)
         ch = logging.StreamHandler()
-        client_logger.setLevel(logging.DEBUG)
+        self.client_logger.setLevel(logging.DEBUG)
-        client_logger.addHandler(ch)
+        self.client_logger.addHandler(ch)
         if hasattr(requests, 'logging'):
             requests.logging.getLogger(requests.__name__).addHandler(ch)
+
         # required for logging when using a keystone session
-        ks_logger = logging.getLogger("keystoneclient")
+        self.ks_logger = logging.getLogger("keystoneclient")
-        ks_logger.setLevel(logging.DEBUG)
+        self.ks_logger.setLevel(logging.DEBUG)
 
     def _delimit_metadata_args(self, argv):
         """This function adds -- separator at the appropriate spot
@@ -633,22 +638,24 @@ class OpenStackCinderShell(object):
 
         insecure = self.options.insecure
 
-        self.cs = client.Client(api_version, os_username,
+        self.cs = client.Client(
-                                os_password, os_tenant_name, os_auth_url,
+            api_version, os_username,
-                                region_name=os_region_name,
+            os_password, os_tenant_name, os_auth_url,
-                                tenant_id=os_tenant_id,
+            region_name=os_region_name,
-                                endpoint_type=endpoint_type,
+            tenant_id=os_tenant_id,
-                                extensions=self.extensions,
+            endpoint_type=endpoint_type,
-                                service_type=service_type,
+            extensions=self.extensions,
-                                service_name=service_name,
+            service_type=service_type,
-                                volume_service_name=volume_service_name,
+            service_name=service_name,
-                                bypass_url=bypass_url,
+            volume_service_name=volume_service_name,
-                                retries=options.retries,
+            bypass_url=bypass_url,
-                                http_log_debug=args.debug,
+            retries=options.retries,
-                                insecure=insecure,
+            http_log_debug=args.debug,
-                                cacert=cacert, auth_system=os_auth_system,
+            insecure=insecure,
-                                auth_plugin=auth_plugin,
+            cacert=cacert, auth_system=os_auth_system,
-                                session=auth_session)
+            auth_plugin=auth_plugin,
+            session=auth_session,
+            logger=self.ks_logger if auth_session else self.client_logger)
 
         try:
             if not utils.isunauthenticated(args.func):

cinderclient/tests/unit/test_client.py

@@ -79,10 +79,11 @@ class ClientTest(utils.TestCase):
                           cinderclient.client.get_volume_api_from_url,
                           unknown_url)
 
+    @mock.patch.object(cinderclient.client, '_log_request_id')
     @mock.patch.object(adapter.Adapter, 'request')
     @mock.patch.object(exceptions, 'from_response')
     def test_sessionclient_request_method(
-            self, mock_from_resp, mock_request):
+            self, mock_from_resp, mock_request, mock_log):
         kwargs = {
             "body": {
                 "volume": {
@@ -115,15 +116,17 @@ class ClientTest(utils.TestCase):
         session_client = cinderclient.client.SessionClient(session=mock.Mock())
         response, body = session_client.request(mock.sentinel.url,
                                                 'POST', **kwargs)
+        self.assertEqual(1, mock_log.call_count)
 
         # In this case, from_response method will not get called
         # because response status_code is < 400
         self.assertEqual(202, response.status_code)
         self.assertFalse(mock_from_resp.called)
 
+    @mock.patch.object(cinderclient.client, '_log_request_id')
     @mock.patch.object(adapter.Adapter, 'request')
     def test_sessionclient_request_method_raises_badrequest(
-            self, mock_request):
+            self, mock_request, mock_log):
         kwargs = {
             "body": {
                 "volume": {
@@ -157,6 +160,7 @@ class ClientTest(utils.TestCase):
         # resp.status_code is 400
         self.assertRaises(exceptions.BadRequest, session_client.request,
                           mock.sentinel.url, 'POST', **kwargs)
+        self.assertEqual(1, mock_log.call_count)
 
     @mock.patch.object(exceptions, 'from_response')
     def test_keystone_request_raises_auth_failure_exception(

cinderclient/v2/client.py

@@ -13,6 +13,8 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
+
 from cinderclient import client
 from cinderclient import api_versions
 from cinderclient.v2 import availability_zones
@@ -55,7 +57,8 @@ class Client(object):
                  service_type='volumev2', service_name=None,
                  volume_service_name=None, bypass_url=None, retries=None,
                  http_log_debug=False, cacert=None, auth_system='keystone',
-                 auth_plugin=None, session=None, api_version=None, **kwargs):
+                 auth_plugin=None, session=None, api_version=None,
+                 logger=None, **kwargs):
         # FIXME(comstud): Rename the api_key argument above when we
         # know it's not being used as keyword argument
         password = api_key
@@ -93,6 +96,9 @@ class Client(object):
                     setattr(self, extension.name,
                             extension.manager_class(self))
 
+        if not logger:
+            logger = logging.getLogger(__name__)
+
         self.client = client._construct_http_client(
             username=username,
             password=password,
@@ -116,6 +122,7 @@ class Client(object):
             auth_plugin=auth_plugin,
             session=session,
             api_version=self.api_version,
+            logger=logger,
             **kwargs)
 
     def authenticate(self):

cinderclient/v3/client.py

@@ -13,6 +13,8 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
+
 from cinderclient import client
 from cinderclient import api_versions
 from cinderclient.v3 import availability_zones
@@ -55,7 +57,8 @@ class Client(object):
                  service_type='volumev3', service_name=None,
                  volume_service_name=None, bypass_url=None, retries=None,
                  http_log_debug=False, cacert=None, auth_system='keystone',
-                 auth_plugin=None, session=None, api_version=None, **kwargs):
+                 auth_plugin=None, session=None, api_version=None,
+                 logger=None, **kwargs):
         # FIXME(comstud): Rename the api_key argument above when we
         # know it's not being used as keyword argument
         password = api_key
@@ -93,6 +96,9 @@ class Client(object):
                     setattr(self, extension.name,
                             extension.manager_class(self))
 
+        if not logger:
+            logger = logging.getLogger(__name__)
+
         self.client = client._construct_http_client(
             username=username,
             password=password,
@@ -116,6 +122,7 @@ class Client(object):
             auth_plugin=auth_plugin,
             session=session,
             api_version=self.api_version,
+            logger=logger,
             **kwargs)
 
     def authenticate(self):

releasenotes/notes/log-request-id-148c74d308bcaa14.yaml

@@ -0,0 +1,6 @@
+---
+features:
+  - Added support to log 'x-openstack-request-id' for each api call.
+    Please refer,
+    https://blueprints.launchpad.net/python-cinderclient/+spec/log-request-id
+    for more details.