# HG changeset patch
# User drewp@bigasterisk.com
# Date 2011-06-21 01:59:44
# Node ID fa67869c1dec644ef243a367c31b8db2912529d7
# Parent  4adc35da22b826d784b60d950026a5bc107032ed

add logTime profiler decorator
Ignore-this: db9565c01a72ddd4d04719cba641df62

diff --git a/light9/prof.py b/light9/prof.py
--- a/light9/prof.py
+++ b/light9/prof.py
@@ -1,4 +1,5 @@
-import sys, traceback
+import sys, traceback, time, logging
+log = logging.getLogger()
 
 def run(main, profile=False):
     if not profile:
@@ -9,7 +10,7 @@ def run(main, profile=False):
     p = hotshot.Profile("/tmp/pro")
     p.runcall(main)
     p.close()
-    hotshot.stats.load("/tmp/pro").sort_stats('time').print_stats()
+    hotshot.stats.load("/tmp/pro").sort_stats('cumulative').print_stats()
     
 def watchPoint(filename, lineno, event="call"):
     """whenever we hit this line, print a stack trace. event='call'
@@ -34,3 +35,14 @@ def watchPoint(filename, lineno, event="
     sys.settrace(trace)
 
     # atexit, print the frequencies?
+
+def logTime(func):
+    def inner(*args, **kw):
+        t1 = time.time()
+        try:
+            ret = func(*args, **kw)
+        finally:
+            log.info("Call to %s took %.1f ms" % (
+                func.__name__, 1000 * (time.time() - t1)))
+        return ret
+    return inner