# 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))