Merge pull request #114 from JaviCerveraIngram/CPS-83-logger-adapter

CPS-83: Added LoggerAdapter.

Author: marcserrat

connect/logger/__init__.py

@@ -3,11 +3,12 @@
 # This file is part of the Ingram Micro Cloud Blue Connect SDK.
 # Copyright (c) 2019-2020 Ingram Micro. All Rights Reserved.
 
-from .logger import function_log, logger
+from .logger import function_log, logger, LoggerAdapter
 
 # TODO add auto settings for cloud platforms
 
 __all__ = [
     'function_log',
-    'logger'
+    'logger',
+    'LoggerAdapter'
 ]

connect/logger/logger.py

@@ -17,27 +17,37 @@
 logger = logging.getLogger()
 
 
-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"
-        for handler in custom_logger.handlers:
-            handler.setFormatter(logging.Formatter(sformat))
-
-    # 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(
-                u'Function `{}.{}` return: {}'.format(
-                    self.__class__.__name__, func.__name__, result))
-            return result
-
-        return wrapper
-
-    return decorator
+class LoggerAdapter(logging.LoggerAdapter):
+    def __init__(self, logger_, extra=None):
+        super(LoggerAdapter, self).__init__(logger_, extra or {})
+        self.prefix = None
+        self.replace_handler = None
+
+    def process(self, msg, kwargs):
+        msg, kwargs = super(LoggerAdapter, self).process(msg, kwargs)
+        if self.replace_handler:
+            handlers_copy = self.logger.handlers[:]
+            for handler in handlers_copy:
+                if isinstance(handler, type(self.replace_handler)):
+                    self.logger.removeHandler(handler)
+                    self.logger.addHandler(self.replace_handler)
+        return (
+            '%s %s' % (self.prefix, msg) if self.prefix else msg,
+            kwargs
+        )
+
+    def setLevel(self, level):
+        self.logger.setLevel(level)
+
+
+def function_log(func):
+    # noinspection PyShadowingNames
+    @wraps(func)
+    def wrapper(self, *args, **kwargs):
+        logger.debug('Entering: %s', func.__name__)
+        logger.debug('Function params: {} {}'.format(args, kwargs))
+        result = func(self, *args, **kwargs)
+        logger.debug(u'Function `{}.{}` return: {}'
+                     .format(self.__class__.__name__, func.__name__, result))
+        return result
+    return wrapper

connect/resources/automation_engine.py

@@ -3,11 +3,10 @@
 # This file is part of the Ingram Micro Cloud Blue Connect SDK.
 # Copyright (c) 2019-2020 Ingram Micro. All Rights Reserved.
 
-import copy
 import logging
-from typing import Any, Dict
+from typing import Any, Dict, Optional
 
-from connect.logger import function_log, logger as global_logger
+from connect.logger import function_log, LoggerAdapter
 from connect.models.activation_tile_response import ActivationTileResponse
 from connect.models.base import BaseModel
 from .base import BaseResource
@@ -16,19 +15,23 @@
 
 class AutomationEngine(BaseResource):
     limit = 1000  # type: int
-    logger = logging.getLogger()
+
+    def __init__(self, config=None):
+        super(AutomationEngine, self).__init__(config)
+        self._current_request = None
+        self._logger_adapter = None
 
     def filters(self, status='pending', **kwargs):
         # type: (str, Dict[str, Any]) -> Dict[str, Any]
         return super(AutomationEngine, self).filters(status=status, **kwargs)
 
-    @function_log(custom_logger=logger)
+    @function_log
     def process(self, filters=None):
-        '''
-        # type: (Dict[str, Any]) -> None
-        '''
+        # # type: (Dict[str, Any]) -> None
         for request in self.list(filters):
+            self._set_current_request(request)
             self.dispatch(request)
+            self._set_current_request(None)
 
     def dispatch(self, request):
         # type: (BaseModel) -> str
@@ -39,34 +42,40 @@ def process_request(self, request):
         raise NotImplementedError('Please implement `{}.process_request` method'
                                   .format(self.__class__.__name__))
 
-    @function_log(custom_logger=logger)
+    @function_log
     def approve(self, pk, data):
         # type: (str, dict) -> str
         return self._api.post(path=pk + '/approve/', json=data)[0]
 
-    @function_log(custom_logger=logger)
+    @function_log
     def inquire(self, pk):
         # type: (str) -> str
         return self._api.post(path=pk + '/inquire/', json={})[0]
 
-    @function_log(custom_logger=logger)
+    @function_log
     def fail(self, pk, reason):
         # type: (str, str) -> str
         return self._api.post(path=pk + '/fail/', json={'reason': reason})[0]
 
-    @function_log(custom_logger=logger)
+    @function_log
     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.handlers = 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))
-         for handler in self.__class__.logger.handlers]
+    @property
+    def logger(self):
+        # type: () -> logging.LoggerAdapter
+        request_id = self._current_request.id if self._current_request else 'global'
+        name = self.__class__.__name__ + '.' + request_id
+        if not self._logger_adapter or self._logger_adapter.logger.name != name:
+            self._logger_adapter = LoggerAdapter(logging.getLogger(name))
+        return self._logger_adapter
+
+    def _set_current_request(self, request):
+        # type: (Optional[BaseModel]) -> None
+        self._current_request = request
+        self._set_logger_prefix(request)
+
+    def _set_logger_prefix(self, request):
+        # type: (Optional[BaseModel]) -> None
+        pass

connect/resources/base.py

@@ -63,28 +63,28 @@ 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)
         response = requests.put(**kwargs)
         return self._check_and_pack_response(response)
 
-    @function_log()
+    @function_log
     def delete(self, path='', **kwargs):
         # type: (str, Any) -> Tuple[str, int]
         kwargs = self._fix_request_kwargs(path, kwargs)
@@ -168,7 +168,7 @@ def filters(self, **kwargs):
             filters[key] = val
         return filters
 
-    @function_log()
+    @function_log
     def search(self, filters=None):
         # type: (Dict[str, Any]) -> List[Any]
         filters = filters or self.filters()

connect/resources/fulfillment_automation.py

@@ -4,7 +4,6 @@
 # Copyright (c) 2019-2020 Ingram Micro. All Rights Reserved.
 
 from abc import ABCMeta
-import logging
 
 from deprecation import deprecated
 from typing import Optional
@@ -13,6 +12,7 @@
 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.asset_request import AssetRequest
 from connect.models.param import Param
 from connect.models.fulfillment import Fulfillment
 from connect.models.tier_config_request import TierConfigRequest
@@ -41,7 +41,6 @@ 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
@@ -74,11 +73,9 @@ def filters(self, status='pending', **kwargs):
             filters['asset.product.id__in'] = ','.join(self.config.products)
         return filters
 
-    @function_log(custom_logger=logger)
+    @function_log
     def dispatch(self, request):
         # type: (Fulfillment) -> str
-        self._set_custom_logger(request.asset.id, request.id)
-
         conversation = request.get_conversation(self.config)
 
         try:
@@ -170,7 +167,7 @@ def get_tier_config(self, tier_id, product_id):
         else:
             return None
 
-    @function_log(custom_logger=logger)
+    @function_log
     def update_parameters(self, pk, params):
         """ Sends a list of Param objects to Connect for updating.
 
@@ -193,3 +190,10 @@ def _update_conversation_if_exists(self, conversation, request_id, obj):
             except TypeError as ex:
                 self.logger.error('Error updating conversation for request {}: {}'
                                   .format(request_id, ex))
+
+    def _set_logger_prefix(self, request):
+        # type: (Optional[AssetRequest]) -> None
+        if request:
+            self.logger.prefix = request.id
+        else:
+            self.logger.prefix = ''

connect/resources/tier_account_request_automation.py

@@ -52,7 +52,7 @@ def process(self, filters=None):
         ):
             self.dispatch(request)
 
-    @function_log(custom_logger=logger)
+    @function_log
     def dispatch(self, request):
         result = self.process_request(request)
         if result.action == TierAccountRequestAction.ACCEPT:

connect/resources/tier_config_automation.py

@@ -4,7 +4,7 @@
 # Copyright (c) 2019-2020 Ingram Micro. All Rights Reserved.
 
 from abc import ABCMeta
-import logging
+from typing import Optional
 
 from connect.exceptions import FailRequest, InquireRequest, SkipRequest
 from connect.logger import function_log
@@ -36,7 +36,6 @@ 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
@@ -63,13 +62,10 @@ def filters(self, status='pending', **kwargs):
             filters['configuration.product.id'] = ','.join(self.config.products)
         return filters
 
-    @function_log(custom_logger=logger)
+    @function_log
     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'
@@ -110,7 +106,7 @@ def dispatch(self, request):
 
         return ''
 
-    @function_log(custom_logger=logger)
+    @function_log
     def update_parameters(self, pk, params):
         """ Sends a list of Param objects to Connect for updating.
 
@@ -124,3 +120,10 @@ def update_parameters(self, pk, params):
             path=pk,
             json={'params': mapped_params},
         )[0]
+
+    def _set_logger_prefix(self, request):
+        # type: (Optional[TierConfigRequest]) -> None
+        if request:
+            self.logger.prefix = request.id + ' - ' + request.configuration.account.id
+        else:
+            self.logger.prefix = ''

connect/resources/usage_automation.py

@@ -4,7 +4,6 @@
 # Copyright (c) 2019-2020 Ingram Micro. All Rights Reserved.
 
 import json
-import logging
 from abc import ABCMeta
 from tempfile import NamedTemporaryFile
 
@@ -28,7 +27,6 @@ class UsageAutomation(AutomationEngine):
     __metaclass__ = ABCMeta
     resource = 'listings'
     model_class = UsageFile
-    logger = logging.getLogger('Usage.logger')
 
     def filters(self, status='listed', **kwargs):
         """
@@ -44,9 +42,6 @@ def filters(self, status='listed', **kwargs):
 
     def dispatch(self, request):
         # type: (UsageListing) -> str
-
-        self._set_custom_logger(request.id, request.contract.marketplace.id)
-
         # TODO Shouldn't this raise an exception on ALL automation classes?
         if self.config.products \
                 and request.product.id not in self.config.products:
@@ -63,6 +58,7 @@ def dispatch(self, request):
                 provider_name=request.provider.name,
             )
         )
+
         try:
             result = self.process_request(request)
         except FileCreationError:
@@ -219,3 +215,10 @@ def _upload_spreadsheet(self, usage_file, spreadsheet):
             msg = 'Unexpected server response, returned code {}'.format(status)
             self.logger.error('{} -- Raw response: {}'.format(msg, content))
             raise FileCreationError(msg)
+
+    def _set_logger_prefix(self, request):
+        # type: (Optional[UsageListing]) -> None
+        if request:
+            self.logger.prefix = request.id + ' - ' + request.contract.marketplace.id
+        else:
+            self.logger.prefix = ''