6a96a69234
* refactor: always use console log handler * refactor: json for k8s, plain otherwise * chore: remove syslog from wsgi.py * chore: remove debug.log() * chore: drop syslog from settings.py * refactor: use log.log() in person.utils * refactor: fetch_meeting_attendance->log.log() * chore: gunicorn logs as JSON (wip) * feat: better json log formatting * refactor: improve log config * feat: gunicorn access log fields * fix: remove type hints The gunicorn logger plays tricks with the LogRecord args parameter to let it have string keys instead of being a simple tuple. The mypy tests rightly flag this. Rather than fighting the typing, just remove the hints and leave a comment warning not to use the gunicorn-specific formatter with other loggers.
224 lines
6.9 KiB
Python
224 lines
6.9 KiB
Python
# Copyright The IETF Trust 2012-2019, All Rights Reserved
|
|
import os
|
|
import sys
|
|
import time as timeutils
|
|
import inspect
|
|
|
|
|
|
try:
|
|
from pprint import pformat
|
|
except ImportError:
|
|
pformat = lambda x: x # type: ignore
|
|
|
|
import cProfile
|
|
import traceback as tb
|
|
|
|
# A debug decorator, written by Paul Butler, taken from
|
|
# http://paulbutler.org/archives/python-debugging-with-decorators/
|
|
# Additional functions and decorator functionality added by
|
|
# Henrik Levkowetz
|
|
|
|
__version__ = "0.16"
|
|
|
|
increment = 2
|
|
|
|
debug = False
|
|
|
|
# Number of times to indent output
|
|
# A list is used to force access by reference
|
|
_report_indent = [4]
|
|
_mark = [ timeutils.time() ]
|
|
|
|
def set_indent(i):
|
|
_report_indent[0] = i
|
|
|
|
def trace(fn): # renamed from 'report' by henrik 16 Jun 2011
|
|
"""Decorator to print information about a function
|
|
call for use while debugging.
|
|
Prints function name, arguments, and call number
|
|
when the function is called. Prints this information
|
|
again along with the return value when the function
|
|
returns.
|
|
"""
|
|
def fix(s,n=64):
|
|
import re
|
|
s = re.sub(r'\\t', ' ', s)
|
|
s = re.sub(r'\s+', ' ', s)
|
|
if len(s) > n+3:
|
|
s = s[:n]+"..."
|
|
return s
|
|
def wrap(*params,**kwargs):
|
|
call = wrap.callcount = wrap.callcount + 1
|
|
|
|
indent = ' ' * _report_indent[0]
|
|
fr = tb.format_stack()[-3].strip()[4:] # call from
|
|
fi, co = [ l.strip() for l in fr.splitlines()[:2] ] # file info, code
|
|
fu = "%s.%s()" % (fn.__module__, fn.__name__) # function name
|
|
fc = "%s(%s)" % (fn.__name__, ', '.join( # function call
|
|
[fix(repr(a)) for a in params] +
|
|
["%s = %s" % (a, fix(repr(b))) for a,b in kwargs.items()]
|
|
))
|
|
|
|
if debug:
|
|
sys.stderr.write("\n%s From %s:\n%s | %s\n%s %s\n%s* %s [#%s]\n" %
|
|
(indent, fi, indent, co, indent, fu, indent, fc, call))
|
|
_report_indent[0] += increment
|
|
mark = timeutils.time()
|
|
ret = fn(*params,**kwargs)
|
|
tau = timeutils.time() - mark
|
|
_report_indent[0] -= increment
|
|
if debug:
|
|
sys.stderr.write("%s %s | %.3fs [#%s] ==> %s\n" % (indent, fc, tau, call, fix(repr(ret))))
|
|
|
|
return ret
|
|
wrap.callcount = 0
|
|
if debug:
|
|
from functools import update_wrapper
|
|
return update_wrapper(wrap, fn)
|
|
else:
|
|
return fn
|
|
|
|
def filepos():
|
|
file, line, func, text = tb.extract_stack(None, 2)[0]
|
|
parts = file.split(os.sep)
|
|
name = os.sep.join(parts[-2:])
|
|
indent = ' ' * (_report_indent[0])
|
|
return "%s%s:%s: %s()" % (indent, name, line, func)
|
|
|
|
def mark():
|
|
def show_entry(e):
|
|
sys.stderr.write(" at %s:L%s %s() %s\n" % e)
|
|
if debug:
|
|
indent = ' ' * (_report_indent[0])
|
|
file, line, func, text = tb.extract_stack(None, 2)[0]
|
|
parts = file.split(os.sep)
|
|
name = os.sep.join(parts[-2:])
|
|
sys.stderr.write("%sMark %s:%s\n" % (indent, name, line))
|
|
_mark[0] = timeutils.time()
|
|
|
|
def lap(s):
|
|
if debug:
|
|
clk = timeutils.time()
|
|
tau = clk - _mark[0]
|
|
ts = timeutils.strftime("%H:%M:%S", timeutils.localtime(clk))
|
|
say("%s: %.3fs since mark: %s" % (ts, tau, s))
|
|
|
|
def clock(s):
|
|
if debug:
|
|
lap(s)
|
|
_mark[0] = timeutils.time()
|
|
|
|
def time(fn):
|
|
"""Decorator to print timing information about a function call.
|
|
"""
|
|
def wrap(*params,**kwargs):
|
|
|
|
indent = ' ' * _report_indent[0]
|
|
fc = "%s.%s()" % (fn.__module__, fn.__name__,)
|
|
|
|
mark = timeutils.time()
|
|
ret = fn(*params,**kwargs)
|
|
tau = timeutils.time() - mark
|
|
sys.stderr.write("%s| %s | %.3fs\n" % (indent, fc, tau))
|
|
|
|
return ret
|
|
wrap.callcount = 0
|
|
if debug:
|
|
from functools import update_wrapper
|
|
return update_wrapper(wrap, fn)
|
|
else:
|
|
return fn
|
|
|
|
def show(name):
|
|
if debug:
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s: '%s'\n" % (indent, name, value))
|
|
|
|
def showpos(name):
|
|
if debug:
|
|
file, line, func, text = tb.extract_stack(None, 2)[0]
|
|
parts = file.split(os.sep)
|
|
fn = os.sep.join(parts[-2:])
|
|
#
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s:%s: %s: '%s'\n" % (indent, fn, line, name, value))
|
|
|
|
def pprint(name):
|
|
if debug:
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s:\n" % (indent, name))
|
|
lines = pformat(value).split('\n')
|
|
for line in lines:
|
|
sys.stderr.write("%s %s\n"%(indent, line))
|
|
|
|
def dir(name):
|
|
if debug:
|
|
name = "dir(%s)" % name
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s:\n" % (indent, name))
|
|
lines = pformat(value).split('\n')
|
|
for line in lines:
|
|
sys.stderr.write("%s %s\n"%(indent, line))
|
|
|
|
def type(name):
|
|
if debug:
|
|
name = "type(%s)" % name
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s: %s\n" % (indent, name, value))
|
|
|
|
def say(s):
|
|
if debug:
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s\n" % (indent, s))
|
|
sys.stderr.flush()
|
|
|
|
def profile(fn):
|
|
def wrapper(*args, **kwargs):
|
|
datafn = fn.__name__ + ".profile" # Name the data file sensibly
|
|
prof = cProfile.Profile()
|
|
retval = prof.runcall(fn, *args, **kwargs)
|
|
prof.dump_stats(datafn)
|
|
return retval
|
|
if debug:
|
|
from functools import update_wrapper
|
|
return update_wrapper(wrapper, fn)
|
|
else:
|
|
return fn
|
|
|
|
def traceback(levels=None):
|
|
if debug:
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("\n%s---- Stack ----\n" % indent)
|
|
if levels:
|
|
start = -2-levels
|
|
else:
|
|
start = None
|
|
for s in tb.format_stack()[start:-1]:
|
|
sys.stderr.write("%s%s" % (indent, s))
|
|
sys.stderr.write("%s---------------\n" % indent)
|
|
|
|
def show_caller(level=None):
|
|
if debug:
|
|
indent = ' ' * (_report_indent[0])
|
|
if level is None:
|
|
level = -3
|
|
sys.stderr.write("%sCalled from %s\n" % (indent, tb.format_stack()[level].strip()[4:]))
|
|
|
|
def info(name):
|
|
if debug:
|
|
frame = inspect.stack()[1][0]
|
|
value = eval(name, frame.f_globals, frame.f_locals)
|
|
vtype = eval("type(%s)"%name, frame.f_globals, frame.f_locals)
|
|
indent = ' ' * (_report_indent[0])
|
|
sys.stderr.write("%s%s: '%s' (%s)\n" % (indent, name, value, vtype))
|