From efc41d8624becbd7835e7f17eedccecd0a29fa2f Mon Sep 17 00:00:00 2001 From: Monty Taylor Date: Thu, 16 Feb 2017 07:38:55 -0600 Subject: [PATCH] Change request_id logging to match nova format Nova has a very nice format for logging request_ids that is more readable than what we were putting into the logs. Copy it. Also, stop trying to log request ids for objects we get from python*client. They already have loggers. Change-Id: Ibe4bff3cf91f282920138fe1d9fe7be3198ba6e3 --- shade/_adapter.py | 65 ++++++++++++++++++++++++++++++++--------------- shade/meta.py | 26 +++---------------- 2 files changed, 49 insertions(+), 42 deletions(-) diff --git a/shade/_adapter.py b/shade/_adapter.py index ed431728e..b6cb2530e 100644 --- a/shade/_adapter.py +++ b/shade/_adapter.py @@ -18,6 +18,7 @@ import functools from keystoneauth1 import adapter from six.moves import urllib +from shade import _log from shade import exc from shade import meta from shade import task_manager @@ -87,46 +88,70 @@ class ShadeAdapter(adapter.Adapter): super(ShadeAdapter, self).__init__(*args, **kwargs) self.shade_logger = shade_logger self.manager = manager + self.request_log = _log.setup_logging('shade.request_ids') + + def _log_request_id(self, response, obj=None): + # Log the request id and object id in a specific logger. This way + # someone can turn it on if they're interested in this kind of tracing. + request_id = response.headers.get('x-openstack-request-id') + if not request_id: + return response + tmpl = "{meth} call to {service} for {url} used request id {req}" + kwargs = dict( + meth=response.request.method, + service=self.service_type, + url=response.request.url, + req=request_id) + + if isinstance(obj, dict): + obj_id = obj.get('id', obj.get('uuid')) + if obj_id: + kwargs['obj_id'] = obj_id + tmpl += " returning object {obj_id}" + self.request_log.debug(tmpl.format(**kwargs)) + return response def _munch_response(self, response, result_key=None): exc.raise_from_response(response) if not response.content: # This doens't have any content - return response + return self._log_request_id(response) # Some REST calls do not return json content. Don't decode it. if 'application/json' not in response.headers.get('Content-Type'): - return response + return self._log_request_id(response) try: result_json = response.json() except Exception: - return response + return self._log_request_id(response) - request_id = response.headers.get('x-openstack-request-id') + if isinstance(result_json, list): + self._log_request_id(response) + return meta.obj_list_to_dict(result_json) - if task_manager._is_listlike(result_json): - return meta.obj_list_to_dict( - result_json, request_id=request_id) - - # Wrap the keys() call in list() because in python3 keys returns - # a "dict_keys" iterator-like object rather than a list - json_keys = list(result_json.keys()) - if len(json_keys) > 1 and result_key: - result = result_json[result_key] - elif len(json_keys) == 1: - result = result_json[json_keys[0]] - else: + result = None + if isinstance(result_json, dict): + # Wrap the keys() call in list() because in python3 keys returns + # a "dict_keys" iterator-like object rather than a list + json_keys = list(result_json.keys()) + if len(json_keys) > 1 and result_key: + result = result_json[result_key] + elif len(json_keys) == 1: + result = result_json[json_keys[0]] + if result is None: # Passthrough the whole body - sometimes (hi glance) things # come through without a top-level container. Also, sometimes # you need to deal with pagination result = result_json - if task_manager._is_listlike(result): - return meta.obj_list_to_dict(result, request_id=request_id) - if task_manager._is_objlike(result): - return meta.obj_to_dict(result, request_id=request_id) + self._log_request_id(response, result) + + if isinstance(result, list): + return meta.obj_list_to_dict(result) + elif isinstance(result, dict): + return meta.obj_to_dict(result) return result def request(self, url, method, run_async=False, *args, **kwargs): diff --git a/shade/meta.py b/shade/meta.py index 0e03718f2..cfc01996e 100644 --- a/shade/meta.py +++ b/shade/meta.py @@ -458,15 +458,6 @@ def get_hostvars_from_server(cloud, server, mounts=None): def _log_request_id(obj, request_id): - # Add it, if passed in, even though we're going to pop in a second, - # just to make the logic simpler - if request_id is not None: - obj['x_openstack_request_ids'] = [request_id] - - request_id = None - request_ids = obj.pop('x_openstack_request_ids', None) - if request_ids: - request_id = request_ids[0] if request_id: # Log the request id and object id in a specific logger. This way # someone can turn it on if they're interested in this kind of tracing. @@ -485,7 +476,7 @@ def _log_request_id(obj, request_id): return obj -def obj_to_dict(obj, request_id=None): +def obj_to_dict(obj): """ Turn an object with attributes into a dict suitable for serializing. Some of the things that are returned in OpenStack are objects with @@ -522,26 +513,17 @@ def obj_to_dict(obj, request_id=None): continue if isinstance(value, NON_CALLABLES) and not key.startswith('_'): instance[key] = value - return _log_request_id(instance, request_id) + return instance -def obj_list_to_dict(obj_list, request_id=None): +def obj_list_to_dict(obj_list): """Enumerate through lists of objects and return lists of dictonaries. Some of the objects returned in OpenStack are actually lists of objects, and in order to expose the data structures as JSON, we need to facilitate the conversion to lists of dictonaries. """ - new_list = [] - if not request_id: - request_id = getattr(obj_list, 'request_ids', [None])[0] - if request_id: - log = _log.setup_logging('shade.request_ids') - log.debug("Retrieved a list. Request ID %(request_id)s", - {'request_id': request_id}) - for obj in obj_list: - new_list.append(obj_to_dict(obj)) - return new_list + return [obj_to_dict(obj) for obj in obj_list] def warlock_to_dict(obj):