Improve logging

* add a new log handler for JSON on stdout: JsonLogHandler
* the message entry was dropped by syslog, rename it to full_message
* add a _level_name entry

README.md

@@ -72,7 +72,11 @@ Error catching views will be put in place to return errors as JSON.
 Logging
 -------
 
-A logging backend is provided to send @cee formatted logs to syslog through UDP.
+Two new logging backends are provided:
+
+* `c2cwsgiutils.pyramid_logging.PyramidCeeSysLogHandler`: to send @cee formatted logs to syslog through UDP.
+* `c2cwsgiutils.pyramid_logging.JsonLogHandler`: to output (on stdout or stderr) JSON formatted logs.
+
 Look at the logging configuration part of
 [acceptance_tests/app/production.ini](acceptance_tests/app/production.ini) for a usage example.
 

acceptance_tests/app/production.ini

@@ -33,7 +33,7 @@ c2c.base_path = /c2c
 keys = root, sqlalchemy
 
 [handlers]
-keys = console, logstash
+keys = console, logstash, json
 
 [formatters]
 keys = generic
@@ -60,3 +60,8 @@ format = %(levelname)-5.5s %(name)s %(message)s
 class = c2cwsgiutils.pyramid_logging.PyramidCeeSysLogHandler
 args = [("%(LOG_HOST)s", %(LOG_PORT)s)]
 level = NOTSET
+
+[handler_json]
+class = c2cwsgiutils.pyramid_logging.JsonLogHandler
+args = (sys.stdout,)
+level = NOTSET

acceptance_tests/tests/docker-compose.yml

@@ -10,7 +10,7 @@ app:
     SQL_PROFILER_SECRET: changeme
     DEBUG_VIEW_SECRET: changeme
     LOG_HOST: 172.17.0.1
-    LOG_TYPE: 'console,logstash'
+    LOG_TYPE: 'json,logstash'
     SQL_LOG_LEVEL: DEBUG
     OTHER_LOG_LEVEL: DEBUG
     DEVELOPMENT: 1

c2cwsgiutils/errors.py

@@ -58,13 +58,12 @@ def other_error(exception, request):
 
 def _do_error(request, status, exception):
     LOG.error("%s %s returned status code %s: %s",
-              request.method, request.url, status, str(exception))
-    trace = traceback.format_exc()
-    LOG.error(trace)
+              request.method, request.url, status, str(exception), exc_info=True)
     request.response.status_code = status
     _add_cors(request)
     response = {"message": str(exception), "status": status}
 
     if os.environ.get('DEVELOPMENT', '0') != '0':
+        trace = traceback.format_exc()
         response['stacktrace'] = trace
     return response

c2cwsgiutils/pyramid_logging.py

@@ -7,10 +7,11 @@
 
 A pyramid event handler is installed to setup this filter for the current request.
 """
+import json
 import logging
 import uuid
 
-from cee_syslog_handler import CeeSysLogHandler
+import cee_syslog_handler
 from pyramid.threadlocal import get_current_request
 
 from c2cwsgiutils import _utils
@@ -34,21 +35,52 @@ def filter(self, record):
                 record.matched_route = request.matched_route.name
             record.path = request.path
             record.request_id = request.c2c_request_id
+        record.level_name = record.levelname
         return True
 
 
 _PYRAMID_FILTER = _PyramidFilter()
 
 
-class PyramidCeeSysLogHandler(CeeSysLogHandler):
+def new_make_message_dict(*args, **kargv):
+    """
+    patch cee_syslog_handler to rename message->full_message otherwise this part is dropped by syslog.
+    """
+    msg = orig_make_message_dict(*args, **kargv)
+    if msg['message'] != msg['short_message']:
+        # only output full_message if it's different from short message
+        msg['full_message'] = msg['message']
+    del msg['message']
+    return msg
+
+
+orig_make_message_dict = cee_syslog_handler.make_message_dict
+cee_syslog_handler.make_message_dict = new_make_message_dict
+
+
+class PyramidCeeSysLogHandler(cee_syslog_handler.CeeSysLogHandler):
     """
     A CEE (JSON format) log handler with additional information about the current request.
     """
     def __init__(self, *args):
-        CeeSysLogHandler.__init__(self, *args)
+        super().__init__(*args)
         self.addFilter(_PYRAMID_FILTER)
 
 
+class JsonLogHandler(logging.StreamHandler):
+    """
+    Log to stdout in JSON.
+    """
+    def __init__(self, stream=None):
+        super().__init__(stream)
+        self.addFilter(_PYRAMID_FILTER)
+
+    def format(self, record):
+        message = cee_syslog_handler.make_message_dict(record, debugging_fields=True, extra_fields=True,
+                                                       fqdn=False, localname=None, facility=None)
+        return json.dumps(message)
+
+
 def install_subscriber(config):
     """
     Install the view to configure the loggers, if configured to do so.

setup.py

@@ -2,7 +2,7 @@
 from setuptools import setup, find_packages
 
 
-VERSION = '0.11.4'
+VERSION = '0.12.0'
 HERE = os.path.abspath(os.path.dirname(__file__))
 INSTALL_REQUIRES = open(os.path.join(HERE, 'rel_requirements.txt')).read().splitlines()