123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247 |
- 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")
|