enhance trace decorator to make log messages print actual function/filename/lineno of the to-be-called function.

1 files changed, 37 insertions, 3 deletions

diff --git a/src/py-libs/trace_decorator.py b/src/py-libs/trace_decorator.py
index bb95148..d849c50 100755
--- a/src/py-libs/trace_decorator.py
+++ b/src/py-libs/trace_decorator.py
@@ -5,6 +5,7 @@
 
 from decorator import decorator
 
+import os
 import logging
 moduleLog = logging.getLogger("mock.trace_decorator")
 
@@ -16,19 +17,52 @@ def traceLog(logger = moduleLog):
         # can override by passing logger=foo as function parameter.
         # make sure this doesnt conflict with one of the parameters
         # you are expecting
+
+        filename = os.path.normcase(f.func_code.co_filename)
+        func_name = f.func_code.co_name
+        lineno = f.func_code.co_firstlineno
+
         l2 = kw.get('logger', log)
-        l2.debug("ENTER: %s(%s, %s)" % (f.func_name, args, kw))
+        message = "ENTER %s(" % f.func_name
+        for arg in args:
+            message = message + repr(arg) + ", "
+        for k,v in kw.items():
+            message = message + "%s=%s" % (k,repr(v))
+        message = message + ")"
+
+        l2.handle(l2.makeRecord(l2.name, logging.DEBUG, filename, lineno, message, args=[], exc_info=None, func=func_name))
         try:
             result = "Bad exception raised: Exception was not a derived class of 'Exception'"
             try:
                 result = f(*args, **kw)
             except (KeyboardInterrupt, Exception), e:
                 result = "EXCEPTION RAISED"
-                l2.debug( "EXCEPTION: %s\n" % e, exc_info=1)
+                l2.handle(l2.makeRecord(l2.name, logging.DEBUG, filename, lineno, "EXCEPTION: %s\n" % e, args=[], exc_info=1, func=func_name))
                 raise
         finally:
-            l2.debug( "LEAVE %s --> %s\n" % (f.func_name, result))
+            l2.handle(l2.makeRecord(l2.name, logging.DEBUG, filename, lineno, "LEAVE %s --> %s\n" % (f.func_name, result), args=[], exc_info=None, func=func_name))
 
         return result
     return trace
 
+# unit tests...
+if __name__ == "__main__":
+    log = logging.getLogger("foobar")
+    logging.basicConfig(level=logging.DEBUG,
+                    format='%(asctime)s - %(levelname)s %(filename)s, %(funcName)s, Line: %(lineno)d:  %(message)s',
+                    )
+
+    log.debug(" --> debug")
+    log.error(" --> error")
+
+    @traceLog(log)
+    def testFunc(arg1, arg2="default", *args, **kargs):
+        return 42
+
+    try:
+        testFunc("hello", "world")
+        testFunc("happy", "joy", name="skippy")
+        testFunc("hi")
+    except:
+        import traceback
+        traceback.print_exc()