logging: added json logger to send json formatted logs

This commit is contained in:
RhodeCode Admin 2022-10-13 12:53:37 +02:00
parent 619fd8cc2c
commit 5316da6586
2 changed files with 277 additions and 40 deletions

View file

@ -0,0 +1,236 @@
'''
This library is provided to allow standard python logging
to output log data as JSON formatted strings
'''
import logging
import json
import re
from datetime import date, datetime, time, tzinfo, timedelta
import traceback
import importlib
from inspect import istraceback
from collections import OrderedDict
from rhodecode.lib.logging_formatter import _inject_req_id, ExceptionAwareFormatter
ZERO = timedelta(0)
HOUR = timedelta(hours=1)
class UTC(tzinfo):
"""UTC"""
def utcoffset(self, dt):
return ZERO
def tzname(self, dt):
return "UTC"
def dst(self, dt):
return ZERO
utc = UTC()
# skip natural LogRecord attributes
# http://docs.python.org/library/logging.html#logrecord-attributes
RESERVED_ATTRS = (
'args', 'asctime', 'created', 'exc_info', 'exc_text', 'filename',
'funcName', 'levelname', 'levelno', 'lineno', 'module',
'msecs', 'message', 'msg', 'name', 'pathname', 'process',
'processName', 'relativeCreated', 'stack_info', 'thread', 'threadName')
def merge_record_extra(record, target, reserved):
"""
Merges extra attributes from LogRecord object into target dictionary
:param record: logging.LogRecord
:param target: dict to update
:param reserved: dict or list with reserved keys to skip
"""
for key, value in record.__dict__.items():
# this allows to have numeric keys
if (key not in reserved
and not (hasattr(key, "startswith")
and key.startswith('_'))):
target[key] = value
return target
class JsonEncoder(json.JSONEncoder):
"""
A custom encoder extending the default JSONEncoder
"""
def default(self, obj):
if isinstance(obj, (date, datetime, time)):
return self.format_datetime_obj(obj)
elif istraceback(obj):
return ''.join(traceback.format_tb(obj)).strip()
elif type(obj) == Exception \
or isinstance(obj, Exception) \
or type(obj) == type:
return str(obj)
try:
return super(JsonEncoder, self).default(obj)
except TypeError:
try:
return str(obj)
except Exception:
return None
def format_datetime_obj(self, obj):
return obj.isoformat()
class JsonFormatter(ExceptionAwareFormatter):
"""
A custom formatter to format logging records as json strings.
Extra values will be formatted as str() if not supported by
json default encoder
"""
def __init__(self, *args, **kwargs):
"""
:param json_default: a function for encoding non-standard objects
as outlined in http://docs.python.org/2/library/json.html
:param json_encoder: optional custom encoder
:param json_serializer: a :meth:`json.dumps`-compatible callable
that will be used to serialize the log record.
:param json_indent: an optional :meth:`json.dumps`-compatible numeric value
that will be used to customize the indent of the output json.
:param prefix: an optional string prefix added at the beginning of
the formatted string
:param json_indent: indent parameter for json.dumps
:param json_ensure_ascii: ensure_ascii parameter for json.dumps
:param reserved_attrs: an optional list of fields that will be skipped when
outputting json log record. Defaults to all log record attributes:
http://docs.python.org/library/logging.html#logrecord-attributes
:param timestamp: an optional string/boolean field to add a timestamp when
outputting the json log record. If string is passed, timestamp will be added
to log record using string as key. If True boolean is passed, timestamp key
will be "timestamp". Defaults to False/off.
"""
self.json_default = self._str_to_fn(kwargs.pop("json_default", None))
self.json_encoder = self._str_to_fn(kwargs.pop("json_encoder", None))
self.json_serializer = self._str_to_fn(kwargs.pop("json_serializer", json.dumps))
self.json_indent = kwargs.pop("json_indent", None)
self.json_ensure_ascii = kwargs.pop("json_ensure_ascii", True)
self.prefix = kwargs.pop("prefix", "")
reserved_attrs = kwargs.pop("reserved_attrs", RESERVED_ATTRS)
self.reserved_attrs = dict(zip(reserved_attrs, reserved_attrs))
self.timestamp = kwargs.pop("timestamp", True)
# super(JsonFormatter, self).__init__(*args, **kwargs)
logging.Formatter.__init__(self, *args, **kwargs)
if not self.json_encoder and not self.json_default:
self.json_encoder = JsonEncoder
self._required_fields = self.parse()
self._skip_fields = dict(zip(self._required_fields,
self._required_fields))
self._skip_fields.update(self.reserved_attrs)
def _str_to_fn(self, fn_as_str):
"""
If the argument is not a string, return whatever was passed in.
Parses a string such as package.module.function, imports the module
and returns the function.
:param fn_as_str: The string to parse. If not a string, return it.
"""
if not isinstance(fn_as_str, str):
return fn_as_str
path, _, function = fn_as_str.rpartition('.')
module = importlib.import_module(path)
return getattr(module, function)
def parse(self):
"""
Parses format string looking for substitutions
This method is responsible for returning a list of fields (as strings)
to include in all log messages.
"""
standard_formatters = re.compile(r'\((.+?)\)', re.IGNORECASE)
return standard_formatters.findall(self._fmt)
def add_fields(self, log_record, record, message_dict):
"""
Override this method to implement custom logic for adding fields.
"""
for field in self._required_fields:
log_record[field] = record.__dict__.get(field)
log_record.update(message_dict)
merge_record_extra(record, log_record, reserved=self._skip_fields)
if self.timestamp:
key = self.timestamp if type(self.timestamp) == str else 'timestamp'
log_record[key] = datetime.fromtimestamp(record.created, tz=utc)
def process_log_record(self, log_record):
"""
Override this method to implement custom logic
on the possibly ordered dictionary.
"""
return log_record
def jsonify_log_record(self, log_record):
"""Returns a json string of the log record."""
return self.json_serializer(log_record,
default=self.json_default,
cls=self.json_encoder,
indent=self.json_indent,
ensure_ascii=self.json_ensure_ascii)
def serialize_log_record(self, log_record):
"""Returns the final representation of the log record."""
return "%s%s" % (self.prefix, self.jsonify_log_record(log_record))
def format(self, record):
"""Formats a log record and serializes to json"""
message_dict = {}
# FIXME: logging.LogRecord.msg and logging.LogRecord.message in typeshed
# are always type of str. We shouldn't need to override that.
if isinstance(record.msg, dict):
message_dict = record.msg
record.message = None
else:
record.message = record.getMessage()
# only format time if needed
if "asctime" in self._required_fields:
record.asctime = self.formatTime(record, self.datefmt)
# Display formatted exception, but allow overriding it in the
# user-supplied dict.
if record.exc_info and not message_dict.get('exc_info'):
message_dict['exc_info'] = self.formatException(record.exc_info)
if not message_dict.get('exc_info') and record.exc_text:
message_dict['exc_info'] = record.exc_text
# Display formatted record of stack frames
# default format is a string returned from :func:`traceback.print_stack`
try:
if record.stack_info and not message_dict.get('stack_info'):
message_dict['stack_info'] = self.formatStack(record.stack_info)
except AttributeError:
# Python2.7 doesn't have stack_info.
pass
try:
log_record = OrderedDict()
except NameError:
log_record = {}
_inject_req_id(record, with_prefix=False)
self.add_fields(log_record, record, message_dict)
log_record = self.process_log_record(log_record)
return self.serialize_log_record(log_record)

View file

@ -39,6 +39,28 @@ COLORS = {
}
def _inject_req_id(record, with_prefix=True):
from pyramid.threadlocal import get_current_request
dummy = '00000000-0000-0000-0000-000000000000'
req_id = None
req = get_current_request()
if req:
req_id = getattr(req, 'req_id', None)
if with_prefix:
req_id = 'req_id:%-36s' % (req_id or dummy)
else:
req_id = (req_id or dummy)
record.req_id = req_id
def _add_log_to_debug_bucket(formatted_record):
from pyramid.threadlocal import get_current_request
req = get_current_request()
if req:
req.req_id_bucket.append(formatted_record)
def one_space_trim(s):
if s.find(" ") == -1:
return s
@ -107,42 +129,6 @@ class ExceptionAwareFormatter(logging.Formatter):
return local_tb
class ColorFormatter(ExceptionAwareFormatter):
def format(self, record):
"""
Changes record's levelname to use with COLORS enum
"""
levelname = record.levelname
start = COLOR_SEQ % (COLORS[levelname])
def_record = logging.Formatter.format(self, record)
end = RESET_SEQ
colored_record = ''.join([start, def_record, end])
return colored_record
def _inject_req_id(record):
from pyramid.threadlocal import get_current_request
dummy = '00000000-0000-0000-0000-000000000000'
req_id = None
req = get_current_request()
if req:
req_id = getattr(req, 'req_id', None)
req_id = 'req_id:%-36s' % (req_id or dummy)
record.req_id = req_id
def _add_log_to_debug_bucket(formatted_record):
from pyramid.threadlocal import get_current_request
req = get_current_request()
if req:
req.req_id_bucket.append(formatted_record)
class RequestTrackingFormatter(ExceptionAwareFormatter):
def format(self, record):
_inject_req_id(record)
@ -151,20 +137,35 @@ class RequestTrackingFormatter(ExceptionAwareFormatter):
return def_record
class ColorRequestTrackingFormatter(ColorFormatter):
class ColorFormatter(ExceptionAwareFormatter):
def format(self, record):
"""
Changes record's levelname to use with COLORS enum
"""
_inject_req_id(record)
def_record = super(ColorFormatter, self).format(record)
levelname = record.levelname
start = COLOR_SEQ % (COLORS[levelname])
end = RESET_SEQ
colored_record = ''.join([start, def_record, end])
return colored_record
class ColorRequestTrackingFormatter(RequestTrackingFormatter):
def format(self, record):
"""
Changes record's levelname to use with COLORS enum
"""
def_record = super(ColorRequestTrackingFormatter, self).format(record)
levelname = record.levelname
start = COLOR_SEQ % (COLORS[levelname])
def_record = logging.Formatter.format(self, record)
end = RESET_SEQ
colored_record = ''.join([start, def_record, end])
_add_log_to_debug_bucket(def_record)
return colored_record