From f2b88a2c36eea3744db6b3f2f565763bcfb66b32 Mon Sep 17 00:00:00 2001 From: Patrick Valsecchi Date: Tue, 30 May 2017 08:54:43 +0200 Subject: [PATCH] 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 | 6 +++- acceptance_tests/app/production.ini | 7 ++++- acceptance_tests/tests/docker-compose.yml | 2 +- c2cwsgiutils/errors.py | 5 ++- c2cwsgiutils/pyramid_logging.py | 38 +++++++++++++++++++++-- setup.py | 2 +- 6 files changed, 50 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index 390b75bc8..b6b5b9a0b 100644 --- a/README.md +++ b/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. diff --git a/acceptance_tests/app/production.ini b/acceptance_tests/app/production.ini index 36e1413ae..593556815 100644 --- a/acceptance_tests/app/production.ini +++ b/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 diff --git a/acceptance_tests/tests/docker-compose.yml b/acceptance_tests/tests/docker-compose.yml index b18b3afb7..20128b395 100644 --- a/acceptance_tests/tests/docker-compose.yml +++ b/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 diff --git a/c2cwsgiutils/errors.py b/c2cwsgiutils/errors.py index fd86fe973..11eefea9b 100644 --- a/c2cwsgiutils/errors.py +++ b/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 diff --git a/c2cwsgiutils/pyramid_logging.py b/c2cwsgiutils/pyramid_logging.py index 7d2b9c611..2af83febc 100644 --- a/c2cwsgiutils/pyramid_logging.py +++ b/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. diff --git a/setup.py b/setup.py index 8145cbca9..03575875c 100644 --- a/setup.py +++ b/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()