Source code for common.logging_extra

import io
import os
import sys
import copy
import json
import time
import uuid
import socket
import logging
import traceback
from threading import local
from collections import OrderedDict
from contextlib import contextmanager


[docs]def json_handler(obj): # if isinstance(obj, (, datetime.time)): # return obj.isoformat() return repr(obj)
[docs]def json_robust_dumps(obj): return json.dumps(obj, default=json_handler)
[docs]class NiceOrderedDict(OrderedDict): def __str__(self): return json_robust_dumps(self)
[docs]class SwagFormatter(logging.Formatter): def __init__(self, swaglogger): logging.Formatter.__init__(self, None, '%a %b %d %H:%M:%S %Z %Y') self.swaglogger = swaglogger = socket.gethostname()
[docs] def format_dict(self, record): record_dict = NiceOrderedDict() if isinstance(record.msg, dict): record_dict['msg'] = record.msg else: try: record_dict['msg'] = record.getMessage() except (ValueError, TypeError): record_dict['msg'] = [record.msg]+record.args record_dict['ctx'] = self.swaglogger.get_ctx() if record.exc_info: record_dict['exc_info'] = self.formatException(record.exc_info) record_dict['level'] = record.levelname record_dict['levelnum'] = record.levelno record_dict['name'] = record_dict['filename'] = record.filename record_dict['lineno'] = record.lineno record_dict['pathname'] = record.pathname record_dict['module'] = record.module record_dict['funcName'] = record.funcName record_dict['host'] = record_dict['process'] = record.process record_dict['thread'] = record.thread record_dict['threadName'] = record.threadName record_dict['created'] = record.created return record_dict
[docs] def format(self, record): if self.swaglogger is None: raise Exception("must set swaglogger before calling format()") return json_robust_dumps(self.format_dict(record))
[docs]class SwagLogFileFormatter(SwagFormatter):
[docs] def fix_kv(self, k, v): # append type to names to preserve legacy naming in logs # avoids overlapping key namespaces with different types # e.g. creates 'msg' -> 'msg$s' # log.event() creates '' -> '$i' # because overlapping namespace 'msg' caused problems if isinstance(v, (str, bytes)): k += "$s" elif isinstance(v, float): k += "$f" elif isinstance(v, bool): k += "$b" elif isinstance(v, int): k += "$i" elif isinstance(v, dict): nv = {} for ik, iv in v.items(): ik, iv = self.fix_kv(ik, iv) nv[ik] = iv v = nv elif isinstance(v, list): k += "$a" return k, v
[docs] def format(self, record): if isinstance(record, str): v = json.loads(record) else: v = self.format_dict(record) mk, mv = self.fix_kv('msg', v['msg']) del v['msg'] v[mk] = mv v['id'] = uuid.uuid4().hex return json_robust_dumps(v)
[docs]class SwagErrorFilter(logging.Filter):
[docs] def filter(self, record): return record.levelno < logging.ERROR
def _tmpfunc(): return 0 def _srcfile(): return os.path.normcase(_tmpfunc.__code__.co_filename)
[docs]class SwagLogger(logging.Logger): def __init__(self): logging.Logger.__init__(self, "swaglog") self.global_ctx = {} self.log_local = local() self.log_local.ctx = {}
[docs] def local_ctx(self): try: return self.log_local.ctx except AttributeError: self.log_local.ctx = {} return self.log_local.ctx
[docs] def get_ctx(self): return dict(self.local_ctx(), **self.global_ctx)
[docs] @contextmanager def ctx(self, **kwargs): old_ctx = self.local_ctx() self.log_local.ctx = copy.copy(old_ctx) or {} self.log_local.ctx.update(kwargs) try: yield finally: self.log_local.ctx = old_ctx
[docs] def bind(self, **kwargs): self.local_ctx().update(kwargs)
[docs] def bind_global(self, **kwargs): self.global_ctx.update(kwargs)
[docs] def event(self, event, *args, **kwargs): evt = NiceOrderedDict() evt['event'] = event if args: evt['args'] = args evt.update(kwargs) if 'error' in kwargs: self.error(evt) elif 'debug' in kwargs: self.debug(evt) else:
[docs] def timestamp(self, event_name): if LOG_TIMESTAMPS: t = time.monotonic() tstp = NiceOrderedDict() tstp['timestamp'] = NiceOrderedDict() tstp['timestamp']["event"] = event_name tstp['timestamp']["time"] = t*1e9 self.debug(tstp)
[docs] def findCaller(self, stack_info=False, stacklevel=1): """ Find the stack frame of the caller so that we can note the source file name, line number and function name. """ f = sys._getframe(3) #On some versions of IronPython, currentframe() returns None if #IronPython isn't run with -X:Frames. if f is not None: f = f.f_back orig_f = f while f and stacklevel > 1: f = f.f_back stacklevel -= 1 if not f: f = orig_f rv = "(unknown file)", 0, "(unknown function)", None while hasattr(f, "f_code"): co = f.f_code filename = os.path.normcase(co.co_filename) # TODO: is this pylint exception correct? if filename == _srcfile: # pylint: disable=comparison-with-callable f = f.f_back continue sinfo = None if stack_info: sio = io.StringIO() sio.write('Stack (most recent call last):\n') traceback.print_stack(f, file=sio) sinfo = sio.getvalue() if sinfo[-1] == '\n': sinfo = sinfo[:-1] sio.close() rv = (co.co_filename, f.f_lineno, co.co_name, sinfo) break return rv
if __name__ == "__main__": log = SwagLogger() stdout_handler = logging.StreamHandler(sys.stdout) stdout_handler.setLevel(logging.INFO) stdout_handler.addFilter(SwagErrorFilter()) log.addHandler(stdout_handler) stderr_handler = logging.StreamHandler(sys.stderr) stderr_handler.setLevel(logging.ERROR) log.addHandler(stderr_handler)"asdasd %s", "a"){'wut': 1}) log.warning("warning") log.error("error") log.critical("critical") log.event("test", x="y") with log.ctx(): stdout_handler.setFormatter(SwagFormatter(log)) stderr_handler.setFormatter(SwagFormatter(log)) log.bind(user="some user")"in req") print("") log.warning("warning") print("") log.error("error") print("") log.critical("critical") print("") log.event("do_req", a=1, b="c")