refactor

Author: Bob Bui

CHANGELOG.md

@@ -1,102 +1,137 @@
 # Change Log
+
 All notable changes to this project will be documented in this file.
 
 This project adheres to [Semantic Versioning](http://semver.org/).  
 The format is based on [Keep a Changelog](http://keepachangelog.com/).
 
+## 1.4.0rc1 - 2021-04-09
+
+- refactor
+
 ## 1.4.0rc - 2021-04-09
- - add capability to customize extraction of request, response info #68
+
+- add capability to customize extraction of request, response info #68
 
 ## 1.3.0 - 2021-03-25
- - add fastapi support #65
+
+- add fastapi support #65
 
 ## 1.2.11 - 2020-11-07
- - fix Sanip IP information is a str not a list #63
- 
+
+- fix Sanip IP information is a str not a list #63
+
 ## 1.2.10 - 2020-10-15
- - re fix #61 Using root logger + flask outside of flask request context throws RuntimeError
+
+- re fix #61 Using root logger + flask outside of flask request context throws RuntimeError
 
 ## 1.2.9 - 2020-10-15
- - Fix #61 Using root logger + flask outside of flask request context throws RuntimeError
+
+- Fix #61 Using root logger + flask outside of flask request context throws RuntimeError
 
 ## 1.2.8 - 2020-08-27
- - Fix #57
+
+- Fix #57
 
 ## 1.2.7 - 2020-08-27
- - yanked, wrong branch released
+
+- yanked, wrong branch released
 
 ## 1.2.6 - 2020-08-05
- - Fix condition for checking root logger handlers #53
+
+- Fix condition for checking root logger handlers #53
 
 ## 1.2.5 - 2020-08-04
- - fix #44
- 
+
+- fix #44
+
 ## 1.2.4 - 2020-08-03
- - fix #51
+
+- fix #51
 
 ## 1.2.2 - 2020-07-14
- - fix #50
- 
+
+- fix #50
+
 ## 1.2.1 - 2020-07-14
- - fix #49
- 
+
+- fix #49
+
 ## 1.2.0 - 2020-04-10
- - fix #45
- - fix #46
- - refactoring
- - optimization log record
+
+- fix #45
+- fix #46
+- refactoring
+- optimization log record
 
 ## 1.1.0 - 2020-04-10
- - Add the possibility to modify the formatter for request logs.
- 
+
+- Add the possibility to modify the formatter for request logs.
+
 ## 1.0.4 - 2019-07-20
- - fix #30 
+
+- fix #30
 
 ## 1.0.3 - 2019-07-20
- - add missing kwargs for init_non_web
+
+- add missing kwargs for init_non_web
 
 ## 1.0.2 - 2019-07-20
- - add method to support getting request logger by using method json_logging.get_request_logger(), fix #23
+
+- add method to support getting request logger by using method json_logging.get_request_logger(), fix #23
 
 ## 1.0.1 - 2019-07-20
- - prevent log forging, fix #1
+
+- prevent log forging, fix #1
 
 ## 1.0.0 - 2019-07-20
+
 Breaking change:
- - add more specific init method for each framework
- - minor correct for ENABLE_JSON_LOGGING_DEBUG behaviour
- - update few code comments
- 
+
+- add more specific init method for each framework
+- minor correct for ENABLE_JSON_LOGGING_DEBUG behaviour
+- update few code comments
+
 ## 0.1.2 - 2019-06-25
- - fix: add japanese character encoding for json logger #24
- 
+
+- fix: add japanese character encoding for json logger #24
+
 ## 0.1.1 - 2019-05-22
- - fix: connexion under gunicorn has no has_request() #22
- 
+
+- fix: connexion under gunicorn has no has_request() #22
+
 ## 0.1.0 - 2019-05-20
- - Add [Connexion](https://github.com/zalando/connexion) support
+
+- Add [Connexion](https://github.com/zalando/connexion) support
 
 ## 0.0.13 - 2019-05-18
- - Fix #19
+
+- Fix #19
 
 ## 0.0.12 - 2019-02-26
- - Fix #16
+
+- Fix #16
 
 ## 0.0.11 - 2019-01-26
- - Adds functionality to customize the the JSON - change keys, values, etc.
- 
+
+- Adds functionality to customize the the JSON - change keys, values, etc.
+
 ## 0.0.10 - 2018-12-04
- - Support for exception tracing exception
+
+- Support for exception tracing exception
 
 ## 0.0.9 - 2018-10-16
- - Add Quart framework support
+
+- Add Quart framework support
 
 ## 0.0.2 - 2017-12-24
 
 ### Changed
-- fixed https://github.com/thangbn/json-logging-python/pull/2 
+
+- fixed https://github.com/thangbn/json-logging-python/pull/2
 
 ## 0.0.1 - 2017-12-24
 
 ### Changed
+
 - Initial release

README.md

@@ -214,8 +214,6 @@ json_logging.config_root_logger()
 Customer JSON log formatter can be passed to init method. see examples for more detail: [non web](https://github.com/thangbn/json-logging-python/blob/master/example/custom_log_format.py), 
 [web](https://github.com/thangbn/json-logging-python/blob/master/example/custom_log_format_request.py)
 
-Custom extraction of request and response can be done by subclass **json_logging.RequestResponseDataExtractionBase**
-
 
 ## 2.7 Exclude certain URl from request instrumentation
 Certain URL can be excluded from request instrumentation by specifying a list of regex into **init_request_instrument** method like below:

example/custom_log_format_request.py

@@ -7,24 +7,41 @@
 import json_logging
 
 
-class CustomRequestJSONLog(json_logging.JSONLogWebFormatter):
+class CustomRequestJSONLog(json_logging.JSONRequestLogFormatter):
     """
     Customized logger
     """
 
-    def format(self, record):
-        json_customized_log_object = ({
-            "type": "request",
+    def _format_log_object(self, record, request_util):
+        # request and response object can be extracted from record like this
+        request = record.request_response_data._request
+        response = record.request_response_data._response
+
+        json_log_object = super(CustomRequestJSONLog, self)._format_log_object(record, request_util)
+        json_log_object.update({
             "customized_prop": "customized value",
-            "correlation_id": json_logging.get_correlation_id(),
         })
-        return json.dumps(json_customized_log_object)
+        return json_log_object
+
+
+class CustomDefaultRequestResponseDTO(json_logging.DefaultRequestResponseDTO):
+    """
+        custom implementation
+    """
+
+    def __init__(self, request, **kwargs):
+        super(CustomDefaultRequestResponseDTO, self).__init__(request, **kwargs)
+
+    def on_request_complete(self, response):
+        super(CustomDefaultRequestResponseDTO, self).on_request_complete(response)
+        self.status = response.status
 
 
 app = flask.Flask(__name__)
 json_logging.init_flask(enable_json=True)
 json_logging.init_request_instrument(app, exclude_url_patterns=[r'/exclude_from_request_instrumentation'],
-                                     custom_formatter=CustomRequestJSONLog)
+                                     custom_formatter=CustomRequestJSONLog,
+                                     request_response_data_extractor_class=CustomDefaultRequestResponseDTO)
 
 # init the logger as usual
 logger = logging.getLogger("test logger")

json_logging/__init__.py

@@ -98,44 +98,46 @@ def init_non_web(*args, **kw):
     __init(*args, **kw)
 
 
-class RequestResponseDataExtractorBase(dict):
+class RequestResponseDTOBase(dict):
     """
-        class that keep HTTP request information for request instrumentation logging
+        Data transfer object for HTTP request & response information for request instrumentation logging
+        Any key that is stored in this dict will be appended to final JSON log object
     """
 
     def __init__(self, request, **kwargs):
-        super(RequestResponseDataExtractorBase, self).__init__(**kwargs)
+        """
+        invoked when request start, where to extract any necessary information from the request object
+        :param request: request object
+        """
+        super(RequestResponseDTOBase, self).__init__(**kwargs)
+        self._request = request
 
-    def update_response_status(self, response):
-        pass
+    def on_request_complete(self, response):
+        """
+        invoked when request complete, update response information into this object, must be called before invoke request logging statement
+        :param response: response object
+        """
+        self._response = response
 
 
-class RequestResponseDataExtractor(RequestResponseDataExtractorBase):
+class DefaultRequestResponseDTO(RequestResponseDTOBase):
     """
         default implementation
     """
 
     def __init__(self, request, **kwargs):
-        super(RequestResponseDataExtractor, self).__init__(request, **kwargs)
+        super(DefaultRequestResponseDTO, self).__init__(request, **kwargs)
         utcnow = datetime.utcnow()
-        self.request_start = utcnow
-        self.request = request
-        self.request_received_at = util.iso_time_format(utcnow)
+        self._request_start = utcnow
+        self["request_received_at"] = util.iso_time_format(utcnow)
 
     # noinspection PyAttributeOutsideInit
-    def update_response_status(self, response):
-        """
-        update response information into this object, must be called before invoke request logging statement
-        :param response:
-        """
-        response_adapter = _request_util.response_adapter
+    def on_request_complete(self, response):
+        super(DefaultRequestResponseDTO, self).on_request_complete(response)
         utcnow = datetime.utcnow()
-        time_delta = utcnow - self.request_start
-        self.response_time_ms = int(time_delta.total_seconds()) * 1000 + int(time_delta.microseconds / 1000)
-        self.response_status = response_adapter.get_status_code(response)
-        self.response_size_b = response_adapter.get_response_size(response)
-        self.response_content_type = response_adapter.get_content_type(response)
-        self.response_sent_at = util.iso_time_format(utcnow)
+        time_delta = utcnow - self._request_start
+        self["response_time_ms"] = int(time_delta.total_seconds()) * 1000 + int(time_delta.microseconds / 1000)
+        self["response_sent_at"] = util.iso_time_format(utcnow)
 
 
 def __init(framework_name=None, custom_formatter=None, enable_json=False):
@@ -194,7 +196,7 @@ def __init(framework_name=None, custom_formatter=None, enable_json=False):
 
 
 def init_request_instrument(app=None, custom_formatter=None, exclude_url_patterns=[],
-                            request_response_data_extractor_class=RequestResponseDataExtractor):
+                            request_response_data_extractor_class=DefaultRequestResponseDTO):
     """
     Configure the request instrumentation logging configuration for given web app. Must be called after init method
 
@@ -212,8 +214,9 @@ def init_request_instrument(app=None, custom_formatter=None, exclude_url_pattern
         if not issubclass(custom_formatter, logging.Formatter):
             raise ValueError('custom_formatter is not subclass of logging.Formatter', custom_formatter)
 
-    if not issubclass(request_response_data_extractor_class, RequestResponseDataExtractorBase):
-        raise ValueError('request_response_data_extractor_class is not subclass of json_logging.RequestInfoBase', custom_formatter)
+    if not issubclass(request_response_data_extractor_class, RequestResponseDTOBase):
+        raise ValueError('request_response_data_extractor_class is not subclass of json_logging.RequestInfoBase',
+                         custom_formatter)
 
     configurator = _current_framework['app_request_instrumentation_configurator']()
     configurator.config(app, request_response_data_extractor_class, exclude_url_patterns=exclude_url_patterns)
@@ -275,10 +278,13 @@ class JSONRequestLogFormatter(BaseJSONFormatter):
 
     def _format_log_object(self, record, request_util):
         json_log_object = super(JSONRequestLogFormatter, self)._format_log_object(record, request_util)
-        request = record.request_info.request
         request_adapter = request_util.request_adapter
+        response_adapter = _request_util.response_adapter
+        request = record.request_response_data._request
+        response = record.request_response_data._response
 
         length = request_adapter.get_content_length(request)
+
         json_log_object.update({
             "type": "request",
             "correlation_id": request_util.get_correlation_id(request),
@@ -292,13 +298,13 @@ def _format_log_object(self, record, request_util):
             "request_size_b": util.parse_int(length, -1),
             "remote_host": request_adapter.get_remote_ip(request),
             "remote_port": request_adapter.get_remote_port(request),
-            "request_received_at": record.request_info.request_received_at,
-            "response_time_ms": record.request_info.response_time_ms,
-            "response_status": record.request_info.response_status,
-            "response_size_b": record.request_info.response_size_b,
-            "response_content_type": record.request_info.response_content_type,
-            "response_sent_at": record.request_info.response_sent_at
+            "response_status": response_adapter.get_status_code(response),
+            "response_size_b": response_adapter.get_response_size(response),
+            "response_content_type": response_adapter.get_content_type(response),
         })
+
+        json_log_object.update(record.request_response_data)
+
         return json_log_object
 
 

json_logging/framework/connexion/__init__.py

@@ -51,14 +51,14 @@ def config(self, app, request_response_data_extractor_class, exclude_url_pattern
         @app.app.before_request
         def before_request():
             if is_not_match_any_pattern(_current_request.path, exclude_url_patterns):
-                g.request_info = request_response_data_extractor_class(_current_request)
+                g.request_response_data = request_response_data_extractor_class(_current_request)
 
         @app.app.after_request
         def after_request(response):
-            if hasattr(g, 'request_info'):
-                request_info = g.request_info
-                request_info.update_response_status(response)
-                self.request_logger.info("", extra={'request_info': request_info})
+            if hasattr(g, 'request_response_data'):
+                request_response_data = g.request_response_data
+                request_response_data.on_request_complete(response)
+                self.request_logger.info("", extra={'request_response_data': request_response_data})
             return response
 
 

json_logging/framework/fastapi/implementation.py

@@ -31,11 +31,11 @@ async def dispatch(self, request: Request, call_next: RequestResponseEndpoint) -
         if not log_request:
             return await call_next(request)
 
-        request_info = _request_config_class(request)
+        request_response_data = _request_config_class(request)
         response = await call_next(request)
-        request_info.update_response_status(response)
+        request_response_data.on_request_complete(response)
         self.request_logger.info(
-            "", extra={"request_info": request_info, "type": "request"}
+            "", extra={"request_response_data": request_response_data, "type": "request"}
         )
         return response