Merge pull request #67 from JaviCerveraIngram/CPS-43-logger-improvements

Cps 43 logger improvements

Author: vgrebenschikov

connect/logger/logger.py

@@ -7,38 +7,37 @@
 import json
 import logging
 import os
-
 from logging.config import dictConfig
-from connect.models.base import BaseModel
 
 with open(os.path.join(os.path.dirname(__file__), 'config.json')) as config_file:
     config = json.load(config_file)
 
 dictConfig(config['logging'])
+
 logger = logging.getLogger()
 
 
-def log_request_data(args):
-    if len(args) and isinstance(args[0], BaseModel):
-        global logger
-        base = " %(levelname)-6s; %(asctime)s; %(name)-6s; %(module)s:%(funcName)s:line"\
-               "-%(lineno)d: %(message)s"
-        sformat = args[0].id + base
-        if hasattr(args[0], 'asset') and hasattr(args[0].asset, 'id'):
-            sformat = args[0].asset.id + "  " + sformat
+def function_log(custom_logger=None):
+    if not custom_logger:
+        custom_logger = logging.getLogger()
+        sformat = " %(levelname)-6s; %(asctime)s; %(name)-6s; %(module)s:%(funcName)s:line" \
+                  "-%(lineno)d: %(message)s"
         [handler.setFormatter(logging.Formatter(sformat, "%I:%M:%S"))
-         for handler in logger.handlers]
-
-
-def function_log(func):
-    @wraps(func)
-    def decorator(self, *args, **kwargs):
-        log_request_data(args)
-        logger.info('Entering: %s', func.__name__)
-        logger.debug('Function params: {} {}'.format(args, kwargs))
-        result = func(self, *args, **kwargs)
-        logger.debug(
-            'Function `{}.{}` return: {}'.format(self.__class__.__name__, func.__name__, result))
-        return result
+         for handler in custom_logger.handlers]
+
+    # noinspection PyUnusedLocal
+    def decorator(func, **kwargs):
+        # noinspection PyShadowingNames
+        @wraps(func)
+        def wrapper(self, *args, **kwargs):
+            custom_logger.info('Entering: %s', func.__name__)
+            custom_logger.debug('Function params: {} {}'.format(args, kwargs))
+            result = func(self, *args, **kwargs)
+            custom_logger.debug(
+                'Function `{}.{}` return: {}'.format(
+                    self.__class__.__name__, func.__name__, result))
+            return result
+
+        return wrapper
 
     return decorator

connect/models/base.py

@@ -57,8 +57,7 @@ def deserialize_json(cls, json_data):
         if error:
             raise TypeError(
                 'Invalid structure for initialization of `{type}`. \n'
-                'Error: {error}. \nJSON data: {data}'
-                .format(
+                'Error: {error}. \nJSON data: {data}'.format(
                     type=cls.__name__,
                     error=error,
                     data=json_data),

connect/resources/automation_engine.py

@@ -3,9 +3,11 @@
 # This file is part of the Ingram Micro Cloud Blue Connect SDK.
 # Copyright (c) 2019 Ingram Micro. All Rights Reserved.
 
+import copy
+import logging
 from typing import Any, Dict
 
-from connect.logger import function_log
+from connect.logger import function_log, logger as global_logger
 from connect.models.activation_tile_response import ActivationTileResponse
 from connect.models.base import BaseModel
 from .base import BaseResource
@@ -14,6 +16,7 @@
 
 class AutomationEngine(BaseResource):
     limit = 1000  # type: int
+    logger = logging.getLogger()
 
     def filters(self, status='pending', **kwargs):
         # type: (str, Dict[str, Any]) -> Dict[str, Any]
@@ -33,22 +36,34 @@ def process_request(self, request):
         raise NotImplementedError('Please implement `{}.process_request` method'
                                   .format(self.__class__.__name__))
 
-    @function_log
+    @function_log(custom_logger=logger)
     def approve(self, pk, data):
         # type: (str, dict) -> str
         return self._api.post(path=pk + '/approve/', json=data)[0]
 
-    @function_log
+    @function_log(custom_logger=logger)
     def inquire(self, pk):
         # type: (str) -> str
         return self._api.post(path=pk + '/inquire/', json={})[0]
 
-    @function_log
+    @function_log(custom_logger=logger)
     def fail(self, pk, reason):
         # type: (str, str) -> str
         return self._api.post(path=pk + '/fail/', json={'reason': reason})[0]
 
-    @function_log
+    @function_log(custom_logger=logger)
     def render_template(self, pk, template_id):
         # type: (str, str) -> ActivationTileResponse
         return TemplateResource(self.config).render(template_id, pk)
+
+    def _set_custom_logger(self, *args):
+        handlers = [copy.copy(hdlr) for hdlr in global_logger.handlers]
+        log_level = global_logger.level
+        self.__class__.logger.setLevel(log_level)
+        self.__class__.logger.propagate = False
+        [self.__class__.logger.addHandler(hdlr) for hdlr in handlers]
+        base = " %(levelname)-6s; %(asctime)s; %(name)-6s; %(module)s:%(funcName)s:line" \
+               "-%(lineno)d: %(message)s"
+        sformat = " ".join(args) + base
+        [handler.setFormatter(logging.Formatter(sformat, "%I:%M:%S"))
+         for handler in self.__class__.logger.handlers]

connect/resources/base.py

@@ -4,14 +4,15 @@
 # Copyright (c) 2019 Ingram Micro. All Rights Reserved.
 
 import functools
+import logging
 from typing import Any, List, Dict, Tuple
 
 import requests
 from requests import compat
 
 from connect.config import Config
 from connect.exceptions import ServerError
-from connect.logger import function_log, logger
+from connect.logger import function_log
 from connect.models.base import BaseModel
 from connect.models.server_error_response import ServerErrorResponse
 
@@ -59,21 +60,21 @@ def urljoin(*args):
             lambda a, b: compat.urljoin(a + ('' if a.endswith('/') else '/'), b) if b else a,
             args)
 
-    @function_log
+    @function_log()
     def get(self, path='', **kwargs):
         # type: (str, Any) -> Tuple[str, int]
         kwargs = self._fix_request_kwargs(path, kwargs)
         response = requests.get(**kwargs)
         return self._check_and_pack_response(response)
 
-    @function_log
+    @function_log()
     def post(self, path='', **kwargs):
         # type: (str, Any) -> Tuple[str, int]
         kwargs = self._fix_request_kwargs(path, kwargs)
         response = requests.post(**kwargs)
         return self._check_and_pack_response(response)
 
-    @function_log
+    @function_log()
     def put(self, path='', **kwargs):
         # type: (str, Any) -> Tuple[str, int]
         kwargs = self._fix_request_kwargs(path, kwargs)
@@ -123,6 +124,7 @@ class BaseResource(object):
     resource = None  # type: str
     limit = 100  # type: int
     model_class = BaseModel
+    logger = logging.getLogger()
 
     def __init__(self, config=None):
         # Set client
@@ -156,6 +158,6 @@ def filters(self, **kwargs):
     def list(self, filters=None):
         # type: (Dict[str, Any]) -> List[Any]
         filters = filters or self.filters()
-        logger.info('Get list request with filters - {}'.format(filters))
+        self.logger.info('Get list request with filters - {}'.format(filters))
         response, _ = self._api.get(params=filters)
         return self.model_class.deserialize(response)

connect/resources/fulfillment_automation.py

@@ -4,12 +4,13 @@
 # Copyright (c) 2019 Ingram Micro. All Rights Reserved.
 
 from abc import ABCMeta
+import logging
 
 from deprecation import deprecated
 from typing import Optional
 
 from connect.exceptions import FailRequest, InquireRequest, SkipRequest
-from connect.logger import logger, function_log
+from connect.logger import function_log
 from connect.models.activation_template_response import ActivationTemplateResponse
 from connect.models.activation_tile_response import ActivationTileResponse
 from connect.models.param import Param
@@ -40,6 +41,7 @@ class FulfillmentAutomation(AutomationEngine):
     __metaclass__ = ABCMeta
     resource = 'requests'
     model_class = Fulfillment
+    logger = logging.getLogger('Fullfilment.logger')
 
     def filters(self, status='pending', **kwargs):
         """ Returns the default set of filters for Fulfillment request, plus any others that you
@@ -72,9 +74,10 @@ def filters(self, status='pending', **kwargs):
             filters['asset.product.id__in'] = ','.join(self.config.products)
         return filters
 
-    @function_log
+    @function_log(custom_logger=logger)
     def dispatch(self, request):
         # type: (Fulfillment) -> str
+        self._set_custom_logger(request.asset.id, request.id)
 
         conversation = request.get_conversation(self.config)
 
@@ -83,11 +86,11 @@ def dispatch(self, request):
                     and request.asset.product.id not in self.config.products:
                 return 'Invalid product'
 
-            logger.info('Start request process / ID request - {}'.format(request.id))
+            self.logger.info('Start request process / ID request - {}'.format(request.id))
             process_result = self.process_request(request)
 
             if not process_result:
-                logger.info('Method `process_request` did not return result')
+                self.logger.info('Method `process_request` did not return result')
                 return ''
 
             if isinstance(process_result, ActivationTileResponse):
@@ -125,8 +128,8 @@ def dispatch(self, request):
             raise
 
         except Exception as ex:
-            logger.warning('Skipping request {} because an exception was raised: {}'
-                           .format(request.id, ex))
+            self.logger.warning('Skipping request {} because an exception was raised: {}'
+                                .format(request.id, ex))
             return ''
 
     def create_request(self, request):
@@ -167,7 +170,7 @@ def get_tier_config(self, tier_id, product_id):
         else:
             return None
 
-    @function_log
+    @function_log(custom_logger=logger)
     def update_parameters(self, pk, params):
         """ Sends a list of Param objects to Connect for updating.
 
@@ -179,18 +182,16 @@ def update_parameters(self, pk, params):
         list_dict = []
         for _ in params:
             list_dict.append(_.__dict__ if isinstance(_, Param) else _)
-
         return self._api.put(
             path=pk,
             json={'asset': {'params': list_dict}},
         )[0]
 
-    @staticmethod
-    def _update_conversation_if_exists(conversation, request_id, obj):
+    def _update_conversation_if_exists(self, conversation, request_id, obj):
         # type: (Optional[Conversation], str, object) -> None
         if conversation:
             try:
                 conversation.add_message(str(obj))
             except TypeError as ex:
-                logger.error('Error updating conversation for request {}: {}'
-                             .format(request_id, ex))
+                self.logger.error('Error updating conversation for request {}: {}'
+                                  .format(request_id, ex))

connect/resources/tier_config_automation.py

@@ -4,9 +4,10 @@
 # Copyright (c) 2019 Ingram Micro. All Rights Reserved.
 
 from abc import ABCMeta
+import logging
 
 from connect.exceptions import FailRequest, InquireRequest, SkipRequest
-from connect.logger import logger, function_log
+from connect.logger import function_log
 from connect.models.activation_template_response import ActivationTemplateResponse
 from connect.models.activation_tile_response import ActivationTileResponse
 from connect.models.param import Param
@@ -35,6 +36,7 @@ class TierConfigAutomation(AutomationEngine):
     __metaclass__ = ABCMeta
     resource = 'tier/config-requests'
     model_class = TierConfigRequest
+    logger = logging.getLogger('Tier.logger')
 
     def filters(self, status='pending', **kwargs):
         """ Returns the default set of filters for Tier Config request, plus any others that you
@@ -61,20 +63,23 @@ def filters(self, status='pending', **kwargs):
             filters['configuration__product__id'] = ','.join(self.config.products)
         return filters
 
-    @function_log
+    @function_log(custom_logger=logger)
     def dispatch(self, request):
         # type: (TierConfigRequest) -> str
         try:
+            self._set_custom_logger(request.id, request.configuration.id,
+                                    request.configuration.account.id)
+
             if self.config.products \
                     and request.configuration.product.id not in self.config.products:
                 return 'Invalid product'
 
-            logger.info(
+            self.logger.info(
                 'Start tier config request process / ID request - {}'.format(request.id))
             result = self.process_request(request)
 
             if not result:
-                logger.info('Method `process_request` did not return result')
+                self.logger.info('Method `process_request` did not return result')
                 return ''
 
             params = {}
@@ -99,13 +104,13 @@ def dispatch(self, request):
             raise
 
         except Exception as ex:
-            logger.warning('Skipping request {} because an exception was raised: {}'
-                           .format(request.id, ex))
+            self.logger.warning('Skipping request {} because an exception was raised: {}'
+                                .format(request.id, ex))
             return ''
 
         return ''
 
-    @function_log
+    @function_log(custom_logger=logger)
     def update_parameters(self, pk, params):
         """ Sends a list of Param objects to Connect for updating.