[4suite-checkins] In 4Suite/tools, files timer.py

Jeremy Kloth jkloth at 4suite.org
Wed Dec 20 23:09:42 MST 2006


Modified Files:
    timer.py

Log Message:
Added callgrind output format for display in KCachegrind

ViewCVS diff:
  http://cvs.4suite.org/viewcvs/4Suite/tools/timer.py.diff?r1=1.3&r2=1.4
ViewCVS view:
  http://cvs.4suite.org/viewcvs/4Suite/tools/timer.py?rev=1.4&content-type=text/vnd.viewcvs-markup

Index: timer.py
===================================================================
RCS file: /var/local/cvsroot/4Suite/tools/timer.py,v
retrieving revision 1.3
retrieving revision 1.4
diff -U2 -r1.3 -r1.4
--- timer.py	26 Nov 2006 23:39:36 -0000	1.3
+++ timer.py	21 Dec 2006 06:09:41 -0000	1.4
@@ -37,8 +37,8 @@
 import time
 try:
-    import cProfile as profile
+    from cProfile import Profile
 except ImportError:
-    import profile
-import pstats
+    from profile import Profile
+from pstats import Stats
 
 default_repeat = 3
@@ -59,9 +59,11 @@
     number = None
     repeat = default_repeat
+    log_file = sys.stderr
     calls = default_calls
     verbose = 0
     precision = 3
     timeit = True
-    profile_sort = 'cum'
+    profile_sort = None
+    callgrind = None
 
     import getopt
@@ -69,5 +71,6 @@
         opts, args = getopt.getopt(args, "n:r:c:pvhPC:",
                                    ["number=", "repeat=", "calls:",
-                                    "profile", "verbose", "help"])
+                                    "profile", "verbose", "help",
+                                    'log-file='])
         for o, a in opts:
             if o in ("-n", "--number"):
@@ -83,4 +86,5 @@
             if o in ("-p", "--profile"):
                 timeit = False
+                profile_sort = 'cum'
             if o in ("-v", "--verbose"):
                 if verbose:
@@ -92,6 +96,7 @@
             if o in ("-P",):
                 timeit = False
-                profile_sort = None
-
+            if o in ('-C',):
+                timeit = False
+                callgrind = a
         if not args:
             raise getopt.error('no input file')
@@ -118,51 +123,51 @@
         return 1
 
+    stats = None
+    best = 0.0
     if timeit:
-        # determine `number` so that 0.2 <= total time < 2.0
-        if number is None:
-            for i in xrange(10):
-                number = 10**i
-                x = default_timer()
-                for i in xrange(number):
-                    script_main()
-                x = default_timer() - x
-                if verbose:
-                    message = "%d loops -> %.*g secs" % (number, precision, x)
-                    print >> sys.stderr, message
-                if x >= 0.2:
-                    break
-
-        timings = []
-        seq = range(number)
-        for i in xrange(repeat):
-            gcold = gc.isenabled()
+        def timeit(number):
+            gc_enabled = gc.isenabled()
             gc.disable()
+            loops = iter(range(number))
             start = default_timer()
-            for i in seq:
+            for n in loops:
                 script_main()
-            end = default_timer()
-            timings.append(end - start)
-            if gcold:
+            timing = default_timer() - start
+            if gc_enabled:
                 gc.enable()
             gc.collect()
+            if verbose:
+                print >> log_file, "%d loops -> %.*g secs" % (
+                    number, precision, timing)
+            return timing
+
+        timings = []
+        while len(timings) < repeat:
+            # determine `number` so that 0.2 <= total time < 2.0
+            if number is None:
+                for n in xrange(10):
+                    number = 10**n
+                    timing = timeit(number)
+                    if timing >= 0.2:
+                        break
+                # use the auto-detected timing as one of the repetitions
+                timings.append(timing)
+            else:
+                timings.append(timeit(number))
         best = min(timings)
-        print >> sys.stderr, "%d loops," % number,
-        value = best * 1e6 / number
     else:
+        number = 1
         profiles = []
-        for i in xrange(repeat):
-            p = profile.Profile()
-            p.runcall(script_main)
-            stats = pstats.Stats(p)
-            profiles.append((stats.total_tt, stats))
+        while len(profiles) < repeat:
+            profile = Profile()
+            profile.runcall(script_main)
+            stats = Stats(profile)
+            timing = stats.total_tt
+            if verbose:
+                print >> log_file, "profile -> %.*g secs" % (precision, timing)
+            profiles.append((timing, stats))
         best, stats = min(profiles)
-        if profile_sort:
-            stats.sort_stats(profile_sort).print_stats(calls)
-        else:
-            browser = ProfileBrowser(stats)
-            browser.cmdloop()
-        value = best * 1e6
 
-    print >> sys.stderr, "best of %d:" % repeat,
+    value = best * 1e6 / number
     if value < 1000:
         unit = "usec"
@@ -174,9 +179,75 @@
             value /= 1000
             unit = "sec"
-    print >> sys.stderr, "%.*g %s" % (precision, value, unit)
+    print >> log_file, "%d loops, best of %d: %.*g %s" % (
+        number, repeat, precision, value, unit)
+
+    if stats:
+        if callgrind:
+            outfile = open(callgrind, 'w')
+            Callgrind(stats).dump(outfile)
+        elif profile_sort:
+            stats.sort_stats(profile_sort).print_stats(calls)
+        else:
+            browser = ProfileBrowser(stats)
+            browser.cmdloop()
     return 0
 
+class Callgrind:
+
+    def __init__(self, stats):
+        self.stats = stats
+        self.flmap = {}
+        self.fnmap = {}
+
+        self.callees = callees = {}
+        for func, (cc, nc, tt, ct, callers) in self.stats.stats.iteritems():
+            if not func in callees:
+                callees[func] = {}
+            for func2, caller in callers.iteritems():
+                if not func2 in callees:
+                    callees[func2] = {}
+                callees[func2][func]  = caller
+        return
+
+    def map_name(self, idmap, name):
+        if name in idmap:
+            return idmap[name]
+        id = len(idmap) + 1
+        idmap[name] = '(%d)' % id
+        return '(%d) %s' % (id, name)
+
+    def dump(self, outfile):
+        print >> outfile, 'events: Ticks'
+        self.dump_summary(outfile)
+        for label, entry in self.stats.stats.iteritems():
+            self.dump_entry(outfile, label, entry)
+
+    def dump_summary(self, outfile):
+        print >> outfile, 'summary:', self.stats.total_tt * 1000000
+        print >> outfile
+
+    def dump_entry(self, outfile, label, entry):
+        filename, firstlineno, name = label
+        cc, nc, tt, ct, callers = entry
+        name = 'Python::%s' % (name)
+        print >> outfile, 'fl=%s' % self.map_name(self. flmap, filename)
+        print >> outfile, 'fn=%s' % self.map_name(self. fnmap, name)
+        print >> outfile, '%d %d' % (firstlineno, tt * 1000000)
+        callees = self.callees.get(label, {})
+        for label, subentry in callees.iteritems():
+            self.dump_subentry(outfile, filename, firstlineno, label, subentry)
+        print >> outfile
+
+    def dump_subentry(self, outfile, sourcefile, sourcelineno, label, subentry):
+        filename, firstlineno, name = label
+        nc, cc, tt, ct = subentry
+        if filename != sourcefile:
+            print >> outfile, 'cfl=%s' % self.map_name(self. flmap, filename)
+        name = 'Python::%s' % (name)
+        print >> outfile, 'cfn=%s' % self.map_name(self. fnmap, name)
+        print >> outfile, 'calls=%d %d' % (nc, firstlineno)
+        print >> outfile, '%d %d' % (sourcelineno, ct * 1000000)
+
 import cmd
-from pstats import Stats
 class ProfileBrowser(cmd.Cmd):
     def __init__(self, stats):


More information about the 4suite-checkins mailing list