248 lines
6.4 KiB
Python
248 lines
6.4 KiB
Python
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
|
|
|
|
LOG_TIMESTAMPS = "LOG_TIMESTAMPS" in os.environ
|
|
|
|
def json_handler(obj):
|
|
# if isinstance(obj, (datetime.date, datetime.time)):
|
|
# return obj.isoformat()
|
|
return repr(obj)
|
|
|
|
def json_robust_dumps(obj):
|
|
return json.dumps(obj, default=json_handler)
|
|
|
|
class NiceOrderedDict(OrderedDict):
|
|
def __str__(self):
|
|
return json_robust_dumps(self)
|
|
|
|
class SwagFormatter(logging.Formatter):
|
|
def __init__(self, swaglogger):
|
|
logging.Formatter.__init__(self, None, '%a %b %d %H:%M:%S %Z %Y')
|
|
|
|
self.swaglogger = swaglogger
|
|
self.host = socket.gethostname()
|
|
|
|
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.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'] = self.host
|
|
record_dict['process'] = record.process
|
|
record_dict['thread'] = record.thread
|
|
record_dict['threadName'] = record.threadName
|
|
record_dict['created'] = record.created
|
|
|
|
return record_dict
|
|
|
|
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))
|
|
|
|
class SwagLogFileFormatter(SwagFormatter):
|
|
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. log.info() creates 'msg' -> 'msg$s'
|
|
# log.event() creates 'msg.health.logMonoTime' -> 'msg.health.logMonoTime$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
|
|
|
|
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)
|
|
|
|
class SwagErrorFilter(logging.Filter):
|
|
def filter(self, record):
|
|
return record.levelno < logging.ERROR
|
|
|
|
def _tmpfunc():
|
|
return 0
|
|
|
|
def _srcfile():
|
|
return os.path.normcase(_tmpfunc.__code__.co_filename)
|
|
|
|
class SwagLogger(logging.Logger):
|
|
def __init__(self):
|
|
logging.Logger.__init__(self, "swaglog")
|
|
|
|
self.global_ctx = {}
|
|
|
|
self.log_local = local()
|
|
self.log_local.ctx = {}
|
|
|
|
def local_ctx(self):
|
|
try:
|
|
return self.log_local.ctx
|
|
except AttributeError:
|
|
self.log_local.ctx = {}
|
|
return self.log_local.ctx
|
|
|
|
def get_ctx(self):
|
|
return dict(self.local_ctx(), **self.global_ctx)
|
|
|
|
@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
|
|
|
|
def bind(self, **kwargs):
|
|
self.local_ctx().update(kwargs)
|
|
|
|
def bind_global(self, **kwargs):
|
|
self.global_ctx.update(kwargs)
|
|
|
|
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:
|
|
self.info(evt)
|
|
|
|
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)
|
|
|
|
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:
|
|
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)
|
|
|
|
log.info("asdasd %s", "a")
|
|
log.info({'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")
|
|
log.info("in req")
|
|
print("")
|
|
log.warning("warning")
|
|
print("")
|
|
log.error("error")
|
|
print("")
|
|
log.critical("critical")
|
|
print("")
|
|
log.event("do_req", a=1, b="c")
|