trim_log_values option for dispatcher

jsonrpcserver/async_dispatcher.py

@@ -1,5 +1,6 @@
 """Asynchronous dispatch"""
 import asyncio
+import logging
 
 from . import config
 from .async_request import AsyncRequest
@@ -17,6 +18,7 @@ async def dispatch(
     debug=None,
     notification_errors=None,
     schema_validation=None,
+    trim_log_values=None,
 ):
     """
     Dispatch a request to a method.
@@ -35,10 +37,11 @@ async def dispatch(
     schema_validation = (
         config.schema_validation if schema_validation is None else schema_validation
     )
+    trim_log_values = config.trim_log_values if trim_log_values is None else trim_log_values
 
     # TODO: Remove this predicate in version 4; configure logging Pythonically
     if config.log_requests:
-        log(request_logger, logging.INFO, requests, fmt="--> %(message)s")
+        log(request_logger, logging.INFO, requests, fmt="--> %(message)s", trim=trim_log_values)
 
     try:
         requests = validate(load_from_json(requests))
@@ -67,5 +70,5 @@ async def dispatch(
 
     # TODO: Remove this predicate in version 4; configure logging Pythonically
     if config.log_responses:
-        log_response(response)
+        log_response(response, trim=trim_log_values)
     return response

jsonrpcserver/config.py

@@ -16,6 +16,9 @@
 #: Log responses
 log_responses = True
 
+#: Log abbreviated versions of requests and responses
+trim_log_values = False
+
 #: Respond to notifications with errors. The JSON-RPC specification says
 #: notifications should not be responded to, so enabling this breaks the spec.
 #: But I prefer to know if there was an error.

jsonrpcserver/dispatcher.py

@@ -19,7 +19,7 @@
 response_logger = logging.getLogger(__name__ + ".response")
 
 
-def log_response(response):
+def log_response(response, trim=None):
     """Log a response"""
     log(
         response_logger,
@@ -30,6 +30,7 @@ def log_response(response):
             "http_code": response.http_status,
             "http_reason": HTTP_STATUS_CODES[response.http_status],
         },
+        trim=trim,
     )
     return None
 
@@ -65,6 +66,7 @@ def dispatch(
     debug=None,
     notification_errors=None,
     schema_validation=None,
+    trim_log_values=None
 ):
     """
     Dispatch a request to a method.
@@ -83,6 +85,7 @@ def dispatch(
     :param notification_errors: Respond with errors to notification requests (breaks
         the JSON-RPC specification, but I prefer to know about errors).
     :param schema_validation: Validate requests against the JSON-RPC schema.
+    :param trim_log_values: Show abbreviated requests and responses in log.
     :returns: A :mod:`response` object.
     """
     # Some ugly code here to support the old config module which will be removed in 4.0,
@@ -99,10 +102,11 @@ def dispatch(
     schema_validation = (
         config.schema_validation if schema_validation is None else schema_validation
     )
+    trim_log_values = config.trim_log_values if trim_log_values is None else trim_log_values
 
     # TODO: Remove this predicate in version 4; configure logging Pythonically
     if config.log_requests:
-        log(request_logger, logging.INFO, requests, fmt="--> %(message)s")
+        log(request_logger, logging.INFO, requests, fmt="--> %(message)s", trim=trim_log_values)
 
     try:
         requests = validate(load_from_json(requests))
@@ -129,5 +133,5 @@ def dispatch(
 
     # TODO: Remove this predicate in version 4; configure logging Pythonically
     if config.log_responses:
-        log_response(response)
+        log_response(response, trim=trim_log_values)
     return response

jsonrpcserver/log.py

@@ -1,5 +1,6 @@
 """Logging"""
 import logging
+import json
 
 
 def configure_logger(logger, fmt):
@@ -16,10 +17,49 @@ def configure_logger(logger, fmt):
         logger.addHandler(handler)
 
 
+def _trim_string(message):
+    longest_string = 30
+
+    if len(message) > longest_string:
+        prefix_len = int(longest_string / 3)
+        suffix_len = prefix_len
+        return message[:prefix_len] + "..." + message[-suffix_len:]
+
+    return message
+
+
+def _trim_values(message_obj):
+    result = {}
+    longest_list = 30
+    for k, val in message_obj.items():
+        if isinstance(val, str):
+            result[k] = _trim_string(val)
+        elif isinstance(val, list) and len(val) > longest_list:
+            prefix_len = int(longest_list / 3)
+            suffix_len = prefix_len
+            result[k] = val[:prefix_len] + ["..."] + val[-suffix_len:]
+        elif isinstance(val, dict):
+            result[k] = _trim_values(val)
+        else:
+            result[k] = val
+    return result
+
+
+def trim_message(message):
+    try:
+        message_obj = json.loads(message)
+        return json.dumps(_trim_values(message_obj))
+    except ValueError:
+        return _trim_string(str(message))
+
+
 def log(logger, level, message, *args, **kwargs):
     """
     Log a message.
     """
     fmt = kwargs.pop("fmt", "%(message)s")
+    trim = kwargs.pop("trim", False)
+    if trim:
+        message = trim_message(message)
     configure_logger(logger, fmt)
     logger.log(level, message, *args, **kwargs)

tests/test_log.py

@@ -1,7 +1,7 @@
 import logging
 from unittest.mock import patch
 
-from jsonrpcserver.log import configure_logger, log
+from jsonrpcserver.log import configure_logger, log, trim_message
 
 
 @patch('logging.root.handlers', [])
@@ -19,3 +19,24 @@ def test_log(caplog):
     logger = logging.getLogger('foo')
     log(logger, logging.INFO, 'foo')
     assert 'foo' in caplog.text
+
+
+def test_trim_message():
+    import json
+    # test string abbreviation
+    message = trim_message("blah" * 100)
+    assert '...' in message
+    # test list abbreviation
+    message = trim_message(json.dumps({"list": [0]*100}))
+    assert '...' in message
+    # test nested abbreviation
+    message = trim_message(json.dumps({
+        "obj": {
+            "list": [0] * 100,
+            "string": "blah" * 100,
+            "obj2": {
+                "string2": "blah" * 100,
+            }
+        }
+    }))
+    assert '...' in json.loads(message)['obj']['obj2']['string2']