422 lines
13 KiB
Python
422 lines
13 KiB
Python
# Written by Brendan O'Connor, brenocon@gmail.com, www.anyall.org
|
|
# * Originally written Aug. 2005
|
|
# * Posted to gist.github.com/16173 on Oct. 2008
|
|
|
|
# Copyright (c) 2003-2006 Open Source Applications Foundation
|
|
#
|
|
# Licensed under the Apache License, Version 2.0 (the "License");
|
|
# you may not use this file except in compliance with the License.
|
|
# You may obtain a copy of the License at
|
|
#
|
|
# http://www.apache.org/licenses/LICENSE-2.0
|
|
#
|
|
# Unless required by applicable law or agreed to in writing, software
|
|
# distributed under the License is distributed on an "AS IS" BASIS,
|
|
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
# See the License for the specific language governing permissions and
|
|
# limitations under the License.
|
|
|
|
import re, sys, types
|
|
|
|
"""
|
|
Have all your function & method calls automatically logged, in indented outline
|
|
form - unlike the stack snapshots in an interactive debugger, it tracks call
|
|
structure & stack depths across time!
|
|
|
|
It hooks into all function calls that you specify, and logs each time they're
|
|
called. I find it especially useful when I don't know what's getting called
|
|
when, or need to continuously test for state changes. (by hacking this file)
|
|
|
|
Originally inspired from the python cookbook:
|
|
http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/198078
|
|
|
|
Currently you can
|
|
- tag functions or individual methods to be autologged
|
|
- tag an entire class's methods to be autologged
|
|
- tag an entire module's classes and functions to be autologged
|
|
|
|
TODO:
|
|
- allow tagging of ALL modules in the program on startup?
|
|
|
|
CAVEATS:
|
|
- certain classes barf when you logclass() them -- most notably,
|
|
SWIG-generated wrappers, and perhaps others.
|
|
|
|
USAGE: see examples on the bottom of this file.
|
|
|
|
|
|
Viewing tips
|
|
============
|
|
|
|
If your terminal can't keep up, try xterm or putty, they seem to be highest
|
|
performance. xterm is available for all platforms through X11...
|
|
|
|
Also try: (RunChandler > log &); tail -f log
|
|
|
|
Also, you can "less -R log" afterward and get the colors correct.
|
|
|
|
If you have long lines, less -RS kills wrapping, enhancing readability. Also
|
|
can chop at formatAllArgs().
|
|
|
|
If you want long lines to be chopped realtime, try piping through less::
|
|
|
|
RunChandler | less -RS
|
|
|
|
but then you have to hit 'space' lots to prevent chandler from freezing.
|
|
less's 'F' command is supposed to do this correctly but doesn't work for me.
|
|
"""
|
|
|
|
|
|
#@@@ should use the standard python logging system?
|
|
log = sys.stdout
|
|
|
|
# Globally incremented across function calls, so tracks stack depth
|
|
indent = 0
|
|
indStr = ' '
|
|
|
|
|
|
# ANSI escape codes for terminals.
|
|
# X11 xterm: always works, all platforms
|
|
# cygwin dosbox: run through |cat and then colors work
|
|
# linux: works on console & gnome-terminal
|
|
# mac: untested
|
|
|
|
|
|
BLACK = "\033[0;30m"
|
|
BLUE = "\033[0;34m"
|
|
GREEN = "\033[0;32m"
|
|
CYAN = "\033[0;36m"
|
|
RED = "\033[0;31m"
|
|
PURPLE = "\033[0;35m"
|
|
BROWN = "\033[0;33m"
|
|
GRAY = "\033[0;37m"
|
|
BOLDGRAY = "\033[1;30m"
|
|
BOLDBLUE = "\033[1;34m"
|
|
BOLDGREEN = "\033[1;32m"
|
|
BOLDCYAN = "\033[1;36m"
|
|
BOLDRED = "\033[1;31m"
|
|
BOLDPURPLE = "\033[1;35m"
|
|
BOLDYELLOW = "\033[1;33m"
|
|
WHITE = "\033[1;37m"
|
|
|
|
NORMAL = "\033[0m"
|
|
|
|
|
|
def indentlog(message):
|
|
global log, indStr, indent
|
|
print("%s%s" %(indStr*indent, message), file=log)
|
|
log.flush()
|
|
|
|
def shortstr(obj):
|
|
"""
|
|
Where to put gritty heuristics to make an object appear in most useful
|
|
form. defaults to __str__.
|
|
"""
|
|
if "wx." in str(obj.__class__) or obj.__class__.__name__.startswith("wx"):
|
|
shortclassname = obj.__class__.__name__
|
|
##shortclassname = str(obj.__class__).split('.')[-1]
|
|
if hasattr(obj, "blockItem") and hasattr(obj.blockItem, "blockName"):
|
|
moreInfo = "block:'%s'" %obj.blockItem.blockName
|
|
else:
|
|
moreInfo = "at %d" %id(obj)
|
|
return "<%s %s>" % (shortclassname, moreInfo)
|
|
else:
|
|
return str(obj)
|
|
|
|
def formatAllArgs(args, kwds):
|
|
"""
|
|
makes a nice string representation of all the arguments
|
|
"""
|
|
allargs = []
|
|
for item in args:
|
|
allargs.append('%s' % shortstr(item))
|
|
for key,item in list(kwds.items()):
|
|
allargs.append('%s=%s' % (key,shortstr(item)))
|
|
formattedArgs = ', '.join(allargs)
|
|
if len(formattedArgs) > 150:
|
|
return formattedArgs[:146] + " ..."
|
|
return formattedArgs
|
|
|
|
|
|
def logmodules(listOfModules):
|
|
for m in listOfModules:
|
|
bindmodule(m)
|
|
|
|
def logmodule(module, logMatch=".*", logNotMatch="nomatchasfdasdf"):
|
|
"""
|
|
WARNING: this seems to break if you import SWIG wrapper classes
|
|
directly into the module namespace ... logclass() creates weirdness when
|
|
used on them, for some reason.
|
|
|
|
@param module: could be either an actual module object, or the string
|
|
you can import (which seems to be the same thing as its
|
|
__name__). So you can say logmodule(__name__) at the end
|
|
of a module definition, to log all of it.
|
|
"""
|
|
|
|
allow = lambda s: re.match(logMatch, s) and not re.match(logNotMatch, s)
|
|
|
|
if isinstance(module, str):
|
|
d = {}
|
|
exec("import %s" % module, d)
|
|
import sys
|
|
module = sys.modules[module]
|
|
|
|
names = list(module.__dict__.keys())
|
|
for name in names:
|
|
if not allow(name): continue
|
|
|
|
value = getattr(module, name)
|
|
if isinstance(value, type):
|
|
setattr(module, name, logclass(value))
|
|
print("autolog.logmodule(): bound %s" %name, file=log)
|
|
elif isinstance(value, types.FunctionType):
|
|
setattr(module, name, logfunction(value))
|
|
print("autolog.logmodule(): bound %s" %name, file=log)
|
|
|
|
def logfunction(theFunction, displayName=None):
|
|
"""a decorator."""
|
|
if not displayName: displayName = theFunction.__name__
|
|
|
|
def _wrapper(*args, **kwds):
|
|
global indent
|
|
argstr = formatAllArgs(args, kwds)
|
|
|
|
# Log the entry into the function
|
|
indentlog("%s%s%s (%s) " % (BOLDRED,displayName,NORMAL, argstr))
|
|
log.flush()
|
|
|
|
indent += 1
|
|
returnval = theFunction(*args,**kwds)
|
|
indent -= 1
|
|
|
|
# Log return
|
|
##indentlog("return: %s"% shortstr(returnval)
|
|
return returnval
|
|
return _wrapper
|
|
|
|
def logmethod(theMethod, displayName=None):
|
|
"""use this for class or instance methods, it formats with the object out front."""
|
|
if not displayName: displayName = theMethod.__name__
|
|
def _methodWrapper(self, *args, **kwds):
|
|
"Use this one for instance or class methods"
|
|
global indent
|
|
|
|
argstr = formatAllArgs(args, kwds)
|
|
selfstr = shortstr(self)
|
|
|
|
#print >> log,"%s%s. %s (%s) " % (indStr*indent,selfstr,methodname,argstr)
|
|
indentlog("%s.%s%s%s (%s) " % (selfstr, BOLDRED,theMethod.__name__,NORMAL, argstr))
|
|
log.flush()
|
|
|
|
indent += 1
|
|
|
|
if theMethod.__name__ == 'OnSize':
|
|
indentlog("position, size = %s%s %s%s" %(BOLDBLUE, self.GetPosition(), self.GetSize(), NORMAL))
|
|
|
|
returnval = theMethod(self, *args,**kwds)
|
|
|
|
indent -= 1
|
|
|
|
return returnval
|
|
return _methodWrapper
|
|
|
|
|
|
def logclass(cls, methodsAsFunctions=False,
|
|
logMatch=".*", logNotMatch="asdfnomatch"):
|
|
"""
|
|
A class "decorator". But python doesn't support decorator syntax for
|
|
classes, so do it manually::
|
|
|
|
class C(object):
|
|
...
|
|
C = logclass(C)
|
|
|
|
@param methodsAsFunctions: set to True if you always want methodname first
|
|
in the display. Probably breaks if you're using class/staticmethods?
|
|
"""
|
|
|
|
allow = lambda s: re.match(logMatch, s) and not re.match(logNotMatch, s) and \
|
|
s not in ('__str__','__repr__')
|
|
|
|
namesToCheck = list(cls.__dict__.keys())
|
|
|
|
for name in namesToCheck:
|
|
if not allow(name): continue
|
|
# unbound methods show up as mere functions in the values of
|
|
# cls.__dict__,so we have to go through getattr
|
|
value = getattr(cls, name)
|
|
|
|
if methodsAsFunctions and callable(value):
|
|
setattr(cls, name, logfunction(value))
|
|
elif isinstance(value, types.MethodType):
|
|
#a normal instance method
|
|
if value.__self__ == None:
|
|
setattr(cls, name, logmethod(value))
|
|
|
|
#class & static method are more complex.
|
|
#a class method
|
|
elif value.__self__ == cls:
|
|
w = logmethod(value.__func__,
|
|
displayName="%s.%s" %(cls.__name__, value.__name__))
|
|
setattr(cls, name, classmethod(w))
|
|
else: assert False
|
|
|
|
#a static method
|
|
elif isinstance(value, types.FunctionType):
|
|
w = logfunction(value,
|
|
displayName="%s.%s" %(cls.__name__, value.__name__))
|
|
setattr(cls, name, staticmethod(w))
|
|
return cls
|
|
|
|
class LogMetaClass(type):
|
|
"""
|
|
Alternative to logclass(), you set this as a class's __metaclass__.
|
|
|
|
It will not work if the metaclass has already been overridden (e.g.
|
|
schema.Item or zope.interface (used in Twisted)
|
|
|
|
Also, it should fail for class/staticmethods, that hasnt been added here
|
|
yet.
|
|
"""
|
|
|
|
def __new__(cls,classname,bases,classdict):
|
|
logmatch = re.compile(classdict.get('logMatch','.*'))
|
|
lognotmatch = re.compile(classdict.get('logNotMatch', 'nevermatchthisstringasdfasdf'))
|
|
|
|
for attr,item in list(classdict.items()):
|
|
if callable(item) and logmatch.match(attr) and not lognotmatch.match(attr):
|
|
classdict['_H_%s'%attr] = item # rebind the method
|
|
classdict[attr] = logmethod(item) # replace method by wrapper
|
|
|
|
return type.__new__(cls,classname,bases,classdict)
|
|
|
|
|
|
|
|
# ---------------------------- Tests and examples ----------------------------
|
|
|
|
if __name__=='__main__':
|
|
print(); print("------------------- single function logging ---------------")
|
|
@logfunction
|
|
def test():
|
|
return 42
|
|
|
|
test()
|
|
|
|
print(); print("------------------- single method logging -----------------")
|
|
class Test1(object):
|
|
def __init__(self):
|
|
self.a = 10
|
|
|
|
@logmethod
|
|
def add(self,a,b): return a+b
|
|
|
|
@logmethod
|
|
def fac(self,val):
|
|
if val == 1:
|
|
return 1
|
|
else:
|
|
return val * self.fac(val-1)
|
|
|
|
@logfunction
|
|
def fac2(self, val):
|
|
if val == 1:
|
|
return 1
|
|
else:
|
|
return val * self.fac2(val-1)
|
|
|
|
t = Test1()
|
|
t.add(5,6)
|
|
t.fac(4)
|
|
print("--- tagged as @logfunction, doesn't understand 'self' is special:")
|
|
t.fac2(4)
|
|
|
|
|
|
print(); print("""-------------------- class "decorator" usage ------------------""")
|
|
class Test2(object):
|
|
#will be ignored
|
|
def __init__(self):
|
|
self.a = 10
|
|
def ignoreThis(self): pass
|
|
|
|
|
|
def add(self,a,b):return a+b
|
|
def fac(self,val):
|
|
if val == 1:
|
|
return 1
|
|
else:
|
|
return val * self.fac(val-1)
|
|
|
|
Test2 = logclass(Test2, logMatch='fac|add')
|
|
|
|
t2 = Test2()
|
|
t2.add(5,6)
|
|
t2.fac(4)
|
|
t2.ignoreThis()
|
|
|
|
|
|
print(); print("-------------------- metaclass usage ------------------")
|
|
class Test3(object, metaclass=LogMetaClass):
|
|
logNotMatch = 'ignoreThis'
|
|
|
|
def __init__(self): pass
|
|
|
|
def fac(self,val):
|
|
if val == 1:
|
|
return 1
|
|
else:
|
|
return val * self.fac(val-1)
|
|
def ignoreThis(self): pass
|
|
t3 = Test3()
|
|
t3.fac(4)
|
|
t3.ignoreThis()
|
|
|
|
print(); print("-------------- testing static & classmethods --------------")
|
|
class Test4(object):
|
|
@classmethod
|
|
def cm(cls, a, b):
|
|
print(cls)
|
|
return a+b
|
|
|
|
def im(self, a, b):
|
|
print(self)
|
|
return a+b
|
|
|
|
@staticmethod
|
|
def sm(a,b): return a+b
|
|
|
|
Test4 = logclass(Test4)
|
|
|
|
Test4.cm(4,3)
|
|
Test4.sm(4,3)
|
|
|
|
t4 = Test4()
|
|
t4.im(4,3)
|
|
t4.sm(4,3)
|
|
t4.cm(4,3)
|
|
|
|
#print; print "-------------- static & classmethods: where to put decorators? --------------"
|
|
#class Test5(object):
|
|
#@classmethod
|
|
#@logmethod
|
|
#def cm(cls, a, b):
|
|
#print cls
|
|
#return a+b
|
|
#@logmethod
|
|
#def im(self, a, b):
|
|
#print self
|
|
#return a+b
|
|
|
|
#@staticmethod
|
|
#@logfunction
|
|
#def sm(a,b): return a+b
|
|
|
|
|
|
#Test5.cm(4,3)
|
|
#Test5.sm(4,3)
|
|
|
|
#t5 = Test5()
|
|
#t5.im(4,3)
|
|
#t5.sm(4,3)
|
|
#t5.cm(4,3)
|