Forgot to add join.js and join_view.html to the git
[unfold.git] / manifold / util / autolog.py
1 # Written by Brendan O'Connor, brenocon@gmail.com, www.anyall.org
2 #  * Originally written Aug. 2005
3 #  * Posted to gist.github.com/16173 on Oct. 2008
4
5 #   Copyright (c) 2003-2006 Open Source Applications Foundation
6 #
7 #   Licensed under the Apache License, Version 2.0 (the "License");
8 #   you may not use this file except in compliance with the License.
9 #   You may obtain a copy of the License at
10 #
11 #       http://www.apache.org/licenses/LICENSE-2.0
12 #
13 #   Unless required by applicable law or agreed to in writing, software
14 #   distributed under the License is distributed on an "AS IS" BASIS,
15 #   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
16 #   See the License for the specific language governing permissions and
17 #   limitations under the License.
18
19 import re, sys, types
20
21 """
22 Have all your function & method calls automatically logged, in indented outline
23 form - unlike the stack snapshots in an interactive debugger, it tracks call
24 structure & stack depths across time!
25
26 It hooks into all function calls that you specify, and logs each time they're
27 called.  I find it especially useful when I don't know what's getting called
28 when, or need to continuously test for state changes.  (by hacking this file)
29
30 Originally inspired from the python cookbook: 
31 http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/198078
32
33 Currently you can
34  - tag functions or individual methods to be autologged
35  - tag an entire class's methods to be autologged
36  - tag an entire module's classes and functions to be autologged
37
38 TODO:
39  - allow tagging of ALL modules in the program on startup?
40
41 CAVEATS:
42  - certain classes barf when you logclass() them -- most notably,
43    SWIG-generated wrappers, and perhaps others.
44
45 USAGE: see examples on the bottom of this file.
46
47
48 Viewing tips
49 ============
50
51 If your terminal can't keep up, try xterm or putty, they seem to be highest
52 performance.  xterm is available for all platforms through X11...
53
54 Also try:    (RunChandler > log &); tail -f log
55
56 Also, you can  "less -R log"  afterward and get the colors correct.
57
58 If you have long lines, less -RS kills wrapping, enhancing readability. Also
59 can chop at formatAllArgs().
60
61 If you want long lines to be chopped realtime, try piping through less::
62
63    RunChandler | less -RS
64
65 but then you have to hit 'space' lots to prevent chandler from freezing.
66 less's 'F' command is supposed to do this correctly but doesn't work for me.
67 """
68
69
70 #@@@ should use the standard python logging system?
71 log = sys.stdout
72
73 # Globally incremented across function calls, so tracks stack depth
74 indent = 0
75 indStr = '  '
76
77
78 # ANSI escape codes for terminals.
79 #  X11 xterm: always works, all platforms
80 #  cygwin dosbox: run through |cat and then colors work
81 #  linux: works on console & gnome-terminal
82 #  mac: untested
83
84
85 BLACK     =        "\033[0;30m"
86 BLUE      =        "\033[0;34m"
87 GREEN     =        "\033[0;32m"
88 CYAN      =       "\033[0;36m"
89 RED       =        "\033[0;31m"
90 PURPLE    =        "\033[0;35m"
91 BROWN     =        "\033[0;33m"
92 GRAY      =        "\033[0;37m"
93 BOLDGRAY  =       "\033[1;30m"
94 BOLDBLUE     =   "\033[1;34m"
95 BOLDGREEN    =   "\033[1;32m"
96 BOLDCYAN     =   "\033[1;36m"
97 BOLDRED      =   "\033[1;31m"
98 BOLDPURPLE   =   "\033[1;35m"
99 BOLDYELLOW   =         "\033[1;33m"
100 WHITE     =        "\033[1;37m"
101
102 NORMAL = "\033[0m"
103
104
105 def indentlog(message):
106     global log, indStr, indent
107     print >>log, "%s%s" %(indStr*indent, message)
108     log.flush()
109
110 def shortstr(obj):
111     """
112     Where to put gritty heuristics to make an object appear in most useful
113     form. defaults to __str__.
114     """
115     if "wx." in str(obj.__class__)  or  obj.__class__.__name__.startswith("wx"):
116         shortclassname = obj.__class__.__name__
117         ##shortclassname = str(obj.__class__).split('.')[-1]
118         if hasattr(obj, "blockItem") and hasattr(obj.blockItem, "blockName"):
119             moreInfo = "block:'%s'" %obj.blockItem.blockName
120         else:
121             moreInfo = "at %d" %id(obj)
122         return "<%s %s>" % (shortclassname, moreInfo)
123     else:
124         return str(obj)
125
126 def formatAllArgs(args, kwds):
127     """
128     makes a nice string representation of all the arguments
129     """
130     allargs = []
131     for item in args:
132         allargs.append('%s' % shortstr(item))
133     for key,item in kwds.items():
134         allargs.append('%s=%s' % (key,shortstr(item)))
135     formattedArgs = ', '.join(allargs)
136     if len(formattedArgs) > 150:
137         return formattedArgs[:146] + " ..."
138     return formattedArgs
139
140
141 def logmodules(listOfModules):
142     for m in listOfModules: 
143         bindmodule(m)
144
145 def logmodule(module, logMatch=".*", logNotMatch="nomatchasfdasdf"):
146     """ 
147     WARNING: this seems to break if you import SWIG wrapper classes
148     directly into the module namespace ... logclass() creates weirdness when
149     used on them, for some reason.
150     
151     @param module: could be either an actual module object, or the string
152                    you can import (which seems to be the same thing as its
153                    __name__).  So you can say logmodule(__name__) at the end
154                    of a module definition, to log all of it.
155     """
156     
157     allow = lambda s: re.match(logMatch, s) and not re.match(logNotMatch, s)
158     
159     if isinstance(module, str):
160         d = {}
161         exec "import %s" % module  in d
162         import sys
163         module = sys.modules[module]
164         
165     names = module.__dict__.keys()
166     for name in names:
167         if not allow(name): continue
168         
169         value = getattr(module, name)
170         if isinstance(value, type):
171             setattr(module, name, logclass(value))
172             print>>log,"autolog.logmodule(): bound %s" %name
173         elif isinstance(value, types.FunctionType):
174             setattr(module, name, logfunction(value))
175             print>>log,"autolog.logmodule(): bound %s" %name
176
177 def logfunction(theFunction, displayName=None):
178     """a decorator."""
179     if not displayName: displayName = theFunction.__name__
180
181     def _wrapper(*args, **kwds):
182         global indent
183         argstr = formatAllArgs(args, kwds)
184         
185         # Log the entry into the function
186         indentlog("%s%s%s  (%s) " % (BOLDRED,displayName,NORMAL, argstr))
187         log.flush()
188         
189         indent += 1
190         returnval = theFunction(*args,**kwds)
191         indent -= 1
192         
193         # Log return
194         ##indentlog("return: %s"% shortstr(returnval)
195         return returnval
196     return _wrapper
197
198 def logmethod(theMethod, displayName=None):
199     """use this for class or instance methods, it formats with the object out front."""
200     if not displayName: displayName = theMethod.__name__
201     def _methodWrapper(self, *args, **kwds):
202         "Use this one for instance or class methods"
203         global indent
204
205         argstr = formatAllArgs(args, kwds)        
206         selfstr = shortstr(self)
207             
208         #print >> log,"%s%s.  %s  (%s) " % (indStr*indent,selfstr,methodname,argstr)
209         indentlog("%s.%s%s%s  (%s) " % (selfstr,  BOLDRED,theMethod.__name__,NORMAL, argstr))
210         log.flush()
211         
212         indent += 1
213         
214         if theMethod.__name__ == 'OnSize':
215             indentlog("position, size = %s%s %s%s" %(BOLDBLUE, self.GetPosition(), self.GetSize(), NORMAL))
216
217         returnval = theMethod(self, *args,**kwds)
218
219         indent -= 1
220         
221         return returnval
222     return _methodWrapper
223
224
225 def logclass(cls, methodsAsFunctions=False, 
226              logMatch=".*", logNotMatch="asdfnomatch"):
227     """ 
228     A class "decorator". But python doesn't support decorator syntax for
229     classes, so do it manually::
230     
231         class C(object):
232            ...
233         C = logclass(C)
234     
235     @param methodsAsFunctions: set to True if you always want methodname first
236     in the display.  Probably breaks if you're using class/staticmethods?
237     """
238
239     allow = lambda s: re.match(logMatch, s) and not re.match(logNotMatch, s) and \
240           s not in ('__str__','__repr__')
241     
242     namesToCheck = cls.__dict__.keys()
243                     
244     for name in namesToCheck:
245         if not allow(name): continue
246         # unbound methods show up as mere functions in the values of
247         # cls.__dict__,so we have to go through getattr
248         value = getattr(cls, name)
249         
250         if methodsAsFunctions and callable(value):
251             setattr(cls, name, logfunction(value))            
252         elif isinstance(value, types.MethodType):
253             #a normal instance method
254             if value.im_self == None:                 
255                 setattr(cls, name, logmethod(value))
256             
257             #class & static method are more complex.
258             #a class method
259             elif value.im_self == cls:                
260                 w = logmethod(value.im_func, 
261                               displayName="%s.%s" %(cls.__name__, value.__name__))
262                 setattr(cls, name, classmethod(w))
263             else: assert False
264
265         #a static method
266         elif isinstance(value, types.FunctionType):
267             w = logfunction(value, 
268                             displayName="%s.%s" %(cls.__name__, value.__name__))
269             setattr(cls, name, staticmethod(w))
270     return cls
271
272 class LogMetaClass(type):
273     """
274     Alternative to logclass(), you set this as a class's __metaclass__.
275     
276     It will not work if the metaclass has already been overridden (e.g.
277     schema.Item or zope.interface (used in Twisted) 
278     
279     Also, it should fail for class/staticmethods, that hasnt been added here
280     yet. 
281     """
282     
283     def __new__(cls,classname,bases,classdict):
284         logmatch = re.compile(classdict.get('logMatch','.*'))
285         lognotmatch = re.compile(classdict.get('logNotMatch', 'nevermatchthisstringasdfasdf'))
286         
287         for attr,item in classdict.items():
288             if callable(item) and logmatch.match(attr) and not lognotmatch.match(attr):
289                 classdict['_H_%s'%attr] = item    # rebind the method
290                 classdict[attr] = logmethod(item) # replace method by wrapper
291
292         return type.__new__(cls,classname,bases,classdict)   
293
294
295             
296 # ---------------------------- Tests and examples ----------------------------
297
298 if __name__=='__main__':
299     print; print "------------------- single function logging ---------------"
300     @logfunction
301     def test():
302         return 42
303     
304     test()
305
306     print; print "------------------- single method logging -----------------"
307     class Test1(object):
308         def __init__(self):
309             self.a = 10
310         
311         @logmethod
312         def add(self,a,b): return a+b
313         
314         @logmethod
315         def fac(self,val):
316             if val == 1:
317                 return 1
318             else:
319                 return val * self.fac(val-1)
320         
321         @logfunction
322         def fac2(self, val):
323             if val == 1:
324                 return 1
325             else:
326                 return val * self.fac2(val-1)            
327     
328     t = Test1()
329     t.add(5,6)
330     t.fac(4)
331     print "--- tagged as @logfunction, doesn't understand 'self' is special:"
332     t.fac2(4)
333         
334
335     print; print """-------------------- class "decorator" usage ------------------"""
336     class Test2(object):
337         #will be ignored
338         def __init__(self):
339             self.a = 10
340         def ignoreThis(self): pass
341         
342
343         def add(self,a,b):return a+b
344         def fac(self,val):
345             if val == 1:
346                 return 1
347             else:
348                 return val * self.fac(val-1)
349     
350     Test2 = logclass(Test2, logMatch='fac|add')
351
352     t2 = Test2()
353     t2.add(5,6)
354     t2.fac(4)
355     t2.ignoreThis()
356     
357     
358     print; print "-------------------- metaclass usage ------------------"
359     class Test3(object):
360         __metaclass__ = LogMetaClass
361         logNotMatch = 'ignoreThis'
362         
363         def __init__(self): pass
364     
365         def fac(self,val):
366             if val == 1:
367                 return 1
368             else:
369                 return val * self.fac(val-1)
370         def ignoreThis(self): pass
371     t3 = Test3()
372     t3.fac(4)
373     t3.ignoreThis()
374
375     print; print "-------------- testing static & classmethods --------------"
376     class Test4(object):
377         @classmethod
378         def cm(cls, a, b): 
379             print cls
380             return a+b
381
382         def im(self, a, b): 
383             print self
384             return a+b
385         
386         @staticmethod
387         def sm(a,b): return a+b
388
389     Test4 = logclass(Test4)
390
391     Test4.cm(4,3)
392     Test4.sm(4,3)
393
394     t4 = Test4()
395     t4.im(4,3)
396     t4.sm(4,3)
397     t4.cm(4,3)
398     
399     #print; print "-------------- static & classmethods: where to put decorators? --------------"
400     #class Test5(object):
401         #@classmethod
402         #@logmethod
403         #def cm(cls, a, b): 
404             #print cls
405             #return a+b
406         #@logmethod
407         #def im(self, a, b): 
408             #print self
409             #return a+b
410         
411         #@staticmethod
412         #@logfunction
413         #def sm(a,b): return a+b
414
415
416     #Test5.cm(4,3)
417     #Test5.sm(4,3)
418
419     #t5 = Test5()
420     #t5.im(4,3)
421     #t5.sm(4,3)
422     #t5.cm(4,3)