Whitespace normalization.
diff --git a/Lib/profile.py b/Lib/profile.py
index feaf287..c32b3f8 100755
--- a/Lib/profile.py
+++ b/Lib/profile.py
@@ -11,7 +11,7 @@
# Copyright 1994, by InfoSeek Corporation, all rights reserved.
# Written by James Roskind
-#
+#
# Permission to use, copy, modify, and distribute this Python software
# and its associated documentation for any purpose (subject to the
# restriction in the following sentence) without fee is hereby granted,
@@ -24,7 +24,7 @@
# to remain in Python, compiled Python, or other languages (such as C)
# wherein the modified or derived code is exclusively imported into a
# Python module.
-#
+#
# INFOSEEK CORPORATION DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS
# SOFTWARE, INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND
# FITNESS. IN NO EVENT SHALL INFOSEEK CORPORATION BE LIABLE FOR ANY
@@ -41,12 +41,12 @@
import marshal
-# Sample timer for use with
+# Sample timer for use with
#i_count = 0
#def integer_timer():
-# global i_count
-# i_count = i_count + 1
-# return i_count
+# global i_count
+# i_count = i_count + 1
+# return i_count
#itimes = integer_timer # replace with C coded timer returning integers
#**************************************************************************
@@ -57,515 +57,515 @@
# simplified user interface
def run(statement, *args):
- prof = Profile()
- try:
- prof = prof.run(statement)
- except SystemExit:
- pass
- if args:
- prof.dump_stats(args[0])
- else:
- return prof.print_stats()
+ prof = Profile()
+ try:
+ prof = prof.run(statement)
+ except SystemExit:
+ pass
+ if args:
+ prof.dump_stats(args[0])
+ else:
+ return prof.print_stats()
# print help
def help():
- for dirname in sys.path:
- fullname = os.path.join(dirname, 'profile.doc')
- if os.path.exists(fullname):
- sts = os.system('${PAGER-more} '+fullname)
- if sts: print '*** Pager exit status:', sts
- break
- else:
- print 'Sorry, can\'t find the help file "profile.doc"',
- print 'along the Python search path'
+ for dirname in sys.path:
+ fullname = os.path.join(dirname, 'profile.doc')
+ if os.path.exists(fullname):
+ sts = os.system('${PAGER-more} '+fullname)
+ if sts: print '*** Pager exit status:', sts
+ break
+ else:
+ print 'Sorry, can\'t find the help file "profile.doc"',
+ print 'along the Python search path'
class Profile:
- """Profiler class.
-
- self.cur is always a tuple. Each such tuple corresponds to a stack
- frame that is currently active (self.cur[-2]). The following are the
- definitions of its members. We use this external "parallel stack" to
- avoid contaminating the program that we are profiling. (old profiler
- used to write into the frames local dictionary!!) Derived classes
- can change the definition of some entries, as long as they leave
- [-2:] intact.
+ """Profiler class.
- [ 0] = Time that needs to be charged to the parent frame's function.
- It is used so that a function call will not have to access the
- timing data for the parent frame.
- [ 1] = Total time spent in this frame's function, excluding time in
- subfunctions
- [ 2] = Cumulative time spent in this frame's function, including time in
- all subfunctions to this frame.
- [-3] = Name of the function that corresponds to this frame.
- [-2] = Actual frame that we correspond to (used to sync exception handling)
- [-1] = Our parent 6-tuple (corresponds to frame.f_back)
+ self.cur is always a tuple. Each such tuple corresponds to a stack
+ frame that is currently active (self.cur[-2]). The following are the
+ definitions of its members. We use this external "parallel stack" to
+ avoid contaminating the program that we are profiling. (old profiler
+ used to write into the frames local dictionary!!) Derived classes
+ can change the definition of some entries, as long as they leave
+ [-2:] intact.
- Timing data for each function is stored as a 5-tuple in the dictionary
- self.timings[]. The index is always the name stored in self.cur[4].
- The following are the definitions of the members:
+ [ 0] = Time that needs to be charged to the parent frame's function.
+ It is used so that a function call will not have to access the
+ timing data for the parent frame.
+ [ 1] = Total time spent in this frame's function, excluding time in
+ subfunctions
+ [ 2] = Cumulative time spent in this frame's function, including time in
+ all subfunctions to this frame.
+ [-3] = Name of the function that corresponds to this frame.
+ [-2] = Actual frame that we correspond to (used to sync exception handling)
+ [-1] = Our parent 6-tuple (corresponds to frame.f_back)
- [0] = The number of times this function was called, not counting direct
- or indirect recursion,
- [1] = Number of times this function appears on the stack, minus one
- [2] = Total time spent internal to this function
- [3] = Cumulative time that this function was present on the stack. In
- non-recursive functions, this is the total execution time from start
- to finish of each invocation of a function, including time spent in
- all subfunctions.
- [5] = A dictionary indicating for each function name, the number of times
- it was called by us.
- """
+ Timing data for each function is stored as a 5-tuple in the dictionary
+ self.timings[]. The index is always the name stored in self.cur[4].
+ The following are the definitions of the members:
- def __init__(self, timer=None):
- self.timings = {}
- self.cur = None
- self.cmd = ""
+ [0] = The number of times this function was called, not counting direct
+ or indirect recursion,
+ [1] = Number of times this function appears on the stack, minus one
+ [2] = Total time spent internal to this function
+ [3] = Cumulative time that this function was present on the stack. In
+ non-recursive functions, this is the total execution time from start
+ to finish of each invocation of a function, including time spent in
+ all subfunctions.
+ [5] = A dictionary indicating for each function name, the number of times
+ it was called by us.
+ """
- self.dispatch = { \
- 'call' : self.trace_dispatch_call, \
- 'return' : self.trace_dispatch_return, \
- 'exception': self.trace_dispatch_exception, \
- }
+ def __init__(self, timer=None):
+ self.timings = {}
+ self.cur = None
+ self.cmd = ""
- if not timer:
- if os.name == 'mac':
- import MacOS
- self.timer = MacOS.GetTicks
- self.dispatcher = self.trace_dispatch_mac
- self.get_time = self.get_time_mac
- elif hasattr(time, 'clock'):
- self.timer = time.clock
- self.dispatcher = self.trace_dispatch_i
- elif hasattr(os, 'times'):
- self.timer = os.times
- self.dispatcher = self.trace_dispatch
- else:
- self.timer = time.time
- self.dispatcher = self.trace_dispatch_i
- else:
- self.timer = timer
- t = self.timer() # test out timer function
- try:
- if len(t) == 2:
- self.dispatcher = self.trace_dispatch
- else:
- self.dispatcher = self.trace_dispatch_l
- except TypeError:
- self.dispatcher = self.trace_dispatch_i
- self.t = self.get_time()
- self.simulate_call('profiler')
+ self.dispatch = { \
+ 'call' : self.trace_dispatch_call, \
+ 'return' : self.trace_dispatch_return, \
+ 'exception': self.trace_dispatch_exception, \
+ }
+
+ if not timer:
+ if os.name == 'mac':
+ import MacOS
+ self.timer = MacOS.GetTicks
+ self.dispatcher = self.trace_dispatch_mac
+ self.get_time = self.get_time_mac
+ elif hasattr(time, 'clock'):
+ self.timer = time.clock
+ self.dispatcher = self.trace_dispatch_i
+ elif hasattr(os, 'times'):
+ self.timer = os.times
+ self.dispatcher = self.trace_dispatch
+ else:
+ self.timer = time.time
+ self.dispatcher = self.trace_dispatch_i
+ else:
+ self.timer = timer
+ t = self.timer() # test out timer function
+ try:
+ if len(t) == 2:
+ self.dispatcher = self.trace_dispatch
+ else:
+ self.dispatcher = self.trace_dispatch_l
+ except TypeError:
+ self.dispatcher = self.trace_dispatch_i
+ self.t = self.get_time()
+ self.simulate_call('profiler')
- def get_time(self): # slow simulation of method to acquire time
- t = self.timer()
- if type(t) == type(()) or type(t) == type([]):
- t = reduce(lambda x,y: x+y, t, 0)
- return t
-
- def get_time_mac(self):
- return self.timer()/60.0
+ def get_time(self): # slow simulation of method to acquire time
+ t = self.timer()
+ if type(t) == type(()) or type(t) == type([]):
+ t = reduce(lambda x,y: x+y, t, 0)
+ return t
- # Heavily optimized dispatch routine for os.times() timer
+ def get_time_mac(self):
+ return self.timer()/60.0
- def trace_dispatch(self, frame, event, arg):
- t = self.timer()
- t = t[0] + t[1] - self.t # No Calibration constant
- # t = t[0] + t[1] - self.t - .00053 # Calibration constant
+ # Heavily optimized dispatch routine for os.times() timer
- if self.dispatch[event](frame,t):
- t = self.timer()
- self.t = t[0] + t[1]
- else:
- r = self.timer()
- self.t = r[0] + r[1] - t # put back unrecorded delta
- return
+ def trace_dispatch(self, frame, event, arg):
+ t = self.timer()
+ t = t[0] + t[1] - self.t # No Calibration constant
+ # t = t[0] + t[1] - self.t - .00053 # Calibration constant
+
+ if self.dispatch[event](frame,t):
+ t = self.timer()
+ self.t = t[0] + t[1]
+ else:
+ r = self.timer()
+ self.t = r[0] + r[1] - t # put back unrecorded delta
+ return
- # Dispatch routine for best timer program (return = scalar integer)
+ # Dispatch routine for best timer program (return = scalar integer)
- def trace_dispatch_i(self, frame, event, arg):
- t = self.timer() - self.t # - 1 # Integer calibration constant
- if self.dispatch[event](frame,t):
- self.t = self.timer()
- else:
- self.t = self.timer() - t # put back unrecorded delta
- return
-
- # Dispatch routine for macintosh (timer returns time in ticks of 1/60th second)
+ def trace_dispatch_i(self, frame, event, arg):
+ t = self.timer() - self.t # - 1 # Integer calibration constant
+ if self.dispatch[event](frame,t):
+ self.t = self.timer()
+ else:
+ self.t = self.timer() - t # put back unrecorded delta
+ return
- def trace_dispatch_mac(self, frame, event, arg):
- t = self.timer()/60.0 - self.t # - 1 # Integer calibration constant
- if self.dispatch[event](frame,t):
- self.t = self.timer()/60.0
- else:
- self.t = self.timer()/60.0 - t # put back unrecorded delta
- return
+ # Dispatch routine for macintosh (timer returns time in ticks of 1/60th second)
+
+ def trace_dispatch_mac(self, frame, event, arg):
+ t = self.timer()/60.0 - self.t # - 1 # Integer calibration constant
+ if self.dispatch[event](frame,t):
+ self.t = self.timer()/60.0
+ else:
+ self.t = self.timer()/60.0 - t # put back unrecorded delta
+ return
- # SLOW generic dispatch routine for timer returning lists of numbers
+ # SLOW generic dispatch routine for timer returning lists of numbers
- def trace_dispatch_l(self, frame, event, arg):
- t = self.get_time() - self.t
+ def trace_dispatch_l(self, frame, event, arg):
+ t = self.get_time() - self.t
- if self.dispatch[event](frame,t):
- self.t = self.get_time()
- else:
- self.t = self.get_time()-t # put back unrecorded delta
- return
+ if self.dispatch[event](frame,t):
+ self.t = self.get_time()
+ else:
+ self.t = self.get_time()-t # put back unrecorded delta
+ return
- def trace_dispatch_exception(self, frame, t):
- rt, rtt, rct, rfn, rframe, rcur = self.cur
- if (not rframe is frame) and rcur:
- return self.trace_dispatch_return(rframe, t)
- return 0
+ def trace_dispatch_exception(self, frame, t):
+ rt, rtt, rct, rfn, rframe, rcur = self.cur
+ if (not rframe is frame) and rcur:
+ return self.trace_dispatch_return(rframe, t)
+ return 0
- def trace_dispatch_call(self, frame, t):
- fcode = frame.f_code
- fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
- self.cur = (t, 0, 0, fn, frame, self.cur)
- if self.timings.has_key(fn):
- cc, ns, tt, ct, callers = self.timings[fn]
- self.timings[fn] = cc, ns + 1, tt, ct, callers
- else:
- self.timings[fn] = 0, 0, 0, 0, {}
- return 1
+ def trace_dispatch_call(self, frame, t):
+ fcode = frame.f_code
+ fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
+ self.cur = (t, 0, 0, fn, frame, self.cur)
+ if self.timings.has_key(fn):
+ cc, ns, tt, ct, callers = self.timings[fn]
+ self.timings[fn] = cc, ns + 1, tt, ct, callers
+ else:
+ self.timings[fn] = 0, 0, 0, 0, {}
+ return 1
- def trace_dispatch_return(self, frame, t):
- # if not frame is self.cur[-2]: raise "Bad return", self.cur[3]
+ def trace_dispatch_return(self, frame, t):
+ # if not frame is self.cur[-2]: raise "Bad return", self.cur[3]
- # Prefix "r" means part of the Returning or exiting frame
- # Prefix "p" means part of the Previous or older frame
+ # Prefix "r" means part of the Returning or exiting frame
+ # Prefix "p" means part of the Previous or older frame
- rt, rtt, rct, rfn, frame, rcur = self.cur
- rtt = rtt + t
- sft = rtt + rct
+ rt, rtt, rct, rfn, frame, rcur = self.cur
+ rtt = rtt + t
+ sft = rtt + rct
- pt, ptt, pct, pfn, pframe, pcur = rcur
- self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
+ pt, ptt, pct, pfn, pframe, pcur = rcur
+ self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
- cc, ns, tt, ct, callers = self.timings[rfn]
- if not ns:
- ct = ct + sft
- cc = cc + 1
- if callers.has_key(pfn):
- callers[pfn] = callers[pfn] + 1 # hack: gather more
- # stats such as the amount of time added to ct courtesy
- # of this specific call, and the contribution to cc
- # courtesy of this call.
- else:
- callers[pfn] = 1
- self.timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
+ cc, ns, tt, ct, callers = self.timings[rfn]
+ if not ns:
+ ct = ct + sft
+ cc = cc + 1
+ if callers.has_key(pfn):
+ callers[pfn] = callers[pfn] + 1 # hack: gather more
+ # stats such as the amount of time added to ct courtesy
+ # of this specific call, and the contribution to cc
+ # courtesy of this call.
+ else:
+ callers[pfn] = 1
+ self.timings[rfn] = cc, ns - 1, tt+rtt, ct, callers
- return 1
+ return 1
- # The next few function play with self.cmd. By carefully preloading
- # our parallel stack, we can force the profiled result to include
- # an arbitrary string as the name of the calling function.
- # We use self.cmd as that string, and the resulting stats look
- # very nice :-).
+ # The next few function play with self.cmd. By carefully preloading
+ # our parallel stack, we can force the profiled result to include
+ # an arbitrary string as the name of the calling function.
+ # We use self.cmd as that string, and the resulting stats look
+ # very nice :-).
- def set_cmd(self, cmd):
- if self.cur[-1]: return # already set
- self.cmd = cmd
- self.simulate_call(cmd)
+ def set_cmd(self, cmd):
+ if self.cur[-1]: return # already set
+ self.cmd = cmd
+ self.simulate_call(cmd)
- class fake_code:
- def __init__(self, filename, line, name):
- self.co_filename = filename
- self.co_line = line
- self.co_name = name
- self.co_firstlineno = 0
+ class fake_code:
+ def __init__(self, filename, line, name):
+ self.co_filename = filename
+ self.co_line = line
+ self.co_name = name
+ self.co_firstlineno = 0
- def __repr__(self):
- return repr((self.co_filename, self.co_line, self.co_name))
+ def __repr__(self):
+ return repr((self.co_filename, self.co_line, self.co_name))
- class fake_frame:
- def __init__(self, code, prior):
- self.f_code = code
- self.f_back = prior
-
- def simulate_call(self, name):
- code = self.fake_code('profile', 0, name)
- if self.cur:
- pframe = self.cur[-2]
- else:
- pframe = None
- frame = self.fake_frame(code, pframe)
- a = self.dispatch['call'](frame, 0)
- return
+ class fake_frame:
+ def __init__(self, code, prior):
+ self.f_code = code
+ self.f_back = prior
- # collect stats from pending stack, including getting final
- # timings for self.cmd frame.
-
- def simulate_cmd_complete(self):
- t = self.get_time() - self.t
- while self.cur[-1]:
- # We *can* cause assertion errors here if
- # dispatch_trace_return checks for a frame match!
- a = self.dispatch['return'](self.cur[-2], t)
- t = 0
- self.t = self.get_time() - t
+ def simulate_call(self, name):
+ code = self.fake_code('profile', 0, name)
+ if self.cur:
+ pframe = self.cur[-2]
+ else:
+ pframe = None
+ frame = self.fake_frame(code, pframe)
+ a = self.dispatch['call'](frame, 0)
+ return
-
- def print_stats(self):
- import pstats
- pstats.Stats(self).strip_dirs().sort_stats(-1). \
- print_stats()
+ # collect stats from pending stack, including getting final
+ # timings for self.cmd frame.
- def dump_stats(self, file):
- f = open(file, 'wb')
- self.create_stats()
- marshal.dump(self.stats, f)
- f.close()
-
- def create_stats(self):
- self.simulate_cmd_complete()
- self.snapshot_stats()
-
- def snapshot_stats(self):
- self.stats = {}
- for func in self.timings.keys():
- cc, ns, tt, ct, callers = self.timings[func]
- callers = callers.copy()
- nc = 0
- for func_caller in callers.keys():
- nc = nc + callers[func_caller]
- self.stats[func] = cc, nc, tt, ct, callers
+ def simulate_cmd_complete(self):
+ t = self.get_time() - self.t
+ while self.cur[-1]:
+ # We *can* cause assertion errors here if
+ # dispatch_trace_return checks for a frame match!
+ a = self.dispatch['return'](self.cur[-2], t)
+ t = 0
+ self.t = self.get_time() - t
- # The following two methods can be called by clients to use
- # a profiler to profile a statement, given as a string.
-
- def run(self, cmd):
- import __main__
- dict = __main__.__dict__
- return self.runctx(cmd, dict, dict)
-
- def runctx(self, cmd, globals, locals):
- self.set_cmd(cmd)
- sys.setprofile(self.dispatcher)
- try:
- exec cmd in globals, locals
- finally:
- sys.setprofile(None)
- return self
+ def print_stats(self):
+ import pstats
+ pstats.Stats(self).strip_dirs().sort_stats(-1). \
+ print_stats()
- # This method is more useful to profile a single function call.
- def runcall(self, func, *args):
- self.set_cmd(`func`)
- sys.setprofile(self.dispatcher)
- try:
- return apply(func, args)
- finally:
- sys.setprofile(None)
+ def dump_stats(self, file):
+ f = open(file, 'wb')
+ self.create_stats()
+ marshal.dump(self.stats, f)
+ f.close()
+
+ def create_stats(self):
+ self.simulate_cmd_complete()
+ self.snapshot_stats()
+
+ def snapshot_stats(self):
+ self.stats = {}
+ for func in self.timings.keys():
+ cc, ns, tt, ct, callers = self.timings[func]
+ callers = callers.copy()
+ nc = 0
+ for func_caller in callers.keys():
+ nc = nc + callers[func_caller]
+ self.stats[func] = cc, nc, tt, ct, callers
- #******************************************************************
- # The following calculates the overhead for using a profiler. The
- # problem is that it takes a fair amount of time for the profiler
- # to stop the stopwatch (from the time it receives an event).
- # Similarly, there is a delay from the time that the profiler
- # re-starts the stopwatch before the user's code really gets to
- # continue. The following code tries to measure the difference on
- # a per-event basis. The result can the be placed in the
- # Profile.dispatch_event() routine for the given platform. Note
- # that this difference is only significant if there are a lot of
- # events, and relatively little user code per event. For example,
- # code with small functions will typically benefit from having the
- # profiler calibrated for the current platform. This *could* be
- # done on the fly during init() time, but it is not worth the
- # effort. Also note that if too large a value specified, then
- # execution time on some functions will actually appear as a
- # negative number. It is *normal* for some functions (with very
- # low call counts) to have such negative stats, even if the
- # calibration figure is "correct."
- #
- # One alternative to profile-time calibration adjustments (i.e.,
- # adding in the magic little delta during each event) is to track
- # more carefully the number of events (and cumulatively, the number
- # of events during sub functions) that are seen. If this were
- # done, then the arithmetic could be done after the fact (i.e., at
- # display time). Currently, we track only call/return events.
- # These values can be deduced by examining the callees and callers
- # vectors for each functions. Hence we *can* almost correct the
- # internal time figure at print time (note that we currently don't
- # track exception event processing counts). Unfortunately, there
- # is currently no similar information for cumulative sub-function
- # time. It would not be hard to "get all this info" at profiler
- # time. Specifically, we would have to extend the tuples to keep
- # counts of this in each frame, and then extend the defs of timing
- # tuples to include the significant two figures. I'm a bit fearful
- # that this additional feature will slow the heavily optimized
- # event/time ratio (i.e., the profiler would run slower, fur a very
- # low "value added" feature.)
- #
- # Plugging in the calibration constant doesn't slow down the
- # profiler very much, and the accuracy goes way up.
- #**************************************************************
-
- def calibrate(self, m):
- # Modified by Tim Peters
- n = m
- s = self.get_time()
- while n:
- self.simple()
- n = n - 1
- f = self.get_time()
- my_simple = f - s
- #print "Simple =", my_simple,
+ # The following two methods can be called by clients to use
+ # a profiler to profile a statement, given as a string.
- n = m
- s = self.get_time()
- while n:
- self.instrumented()
- n = n - 1
- f = self.get_time()
- my_inst = f - s
- # print "Instrumented =", my_inst
- avg_cost = (my_inst - my_simple)/m
- #print "Delta/call =", avg_cost, "(profiler fixup constant)"
- return avg_cost
+ def run(self, cmd):
+ import __main__
+ dict = __main__.__dict__
+ return self.runctx(cmd, dict, dict)
- # simulate a program with no profiler activity
- def simple(self):
- a = 1
- pass
+ def runctx(self, cmd, globals, locals):
+ self.set_cmd(cmd)
+ sys.setprofile(self.dispatcher)
+ try:
+ exec cmd in globals, locals
+ finally:
+ sys.setprofile(None)
+ return self
- # simulate a program with call/return event processing
- def instrumented(self):
- a = 1
- self.profiler_simulation(a, a, a)
+ # This method is more useful to profile a single function call.
+ def runcall(self, func, *args):
+ self.set_cmd(`func`)
+ sys.setprofile(self.dispatcher)
+ try:
+ return apply(func, args)
+ finally:
+ sys.setprofile(None)
- # simulate an event processing activity (from user's perspective)
- def profiler_simulation(self, x, y, z):
- t = self.timer()
- ## t = t[0] + t[1]
- self.ut = t
+
+ #******************************************************************
+ # The following calculates the overhead for using a profiler. The
+ # problem is that it takes a fair amount of time for the profiler
+ # to stop the stopwatch (from the time it receives an event).
+ # Similarly, there is a delay from the time that the profiler
+ # re-starts the stopwatch before the user's code really gets to
+ # continue. The following code tries to measure the difference on
+ # a per-event basis. The result can the be placed in the
+ # Profile.dispatch_event() routine for the given platform. Note
+ # that this difference is only significant if there are a lot of
+ # events, and relatively little user code per event. For example,
+ # code with small functions will typically benefit from having the
+ # profiler calibrated for the current platform. This *could* be
+ # done on the fly during init() time, but it is not worth the
+ # effort. Also note that if too large a value specified, then
+ # execution time on some functions will actually appear as a
+ # negative number. It is *normal* for some functions (with very
+ # low call counts) to have such negative stats, even if the
+ # calibration figure is "correct."
+ #
+ # One alternative to profile-time calibration adjustments (i.e.,
+ # adding in the magic little delta during each event) is to track
+ # more carefully the number of events (and cumulatively, the number
+ # of events during sub functions) that are seen. If this were
+ # done, then the arithmetic could be done after the fact (i.e., at
+ # display time). Currently, we track only call/return events.
+ # These values can be deduced by examining the callees and callers
+ # vectors for each functions. Hence we *can* almost correct the
+ # internal time figure at print time (note that we currently don't
+ # track exception event processing counts). Unfortunately, there
+ # is currently no similar information for cumulative sub-function
+ # time. It would not be hard to "get all this info" at profiler
+ # time. Specifically, we would have to extend the tuples to keep
+ # counts of this in each frame, and then extend the defs of timing
+ # tuples to include the significant two figures. I'm a bit fearful
+ # that this additional feature will slow the heavily optimized
+ # event/time ratio (i.e., the profiler would run slower, fur a very
+ # low "value added" feature.)
+ #
+ # Plugging in the calibration constant doesn't slow down the
+ # profiler very much, and the accuracy goes way up.
+ #**************************************************************
+
+ def calibrate(self, m):
+ # Modified by Tim Peters
+ n = m
+ s = self.get_time()
+ while n:
+ self.simple()
+ n = n - 1
+ f = self.get_time()
+ my_simple = f - s
+ #print "Simple =", my_simple,
+
+ n = m
+ s = self.get_time()
+ while n:
+ self.instrumented()
+ n = n - 1
+ f = self.get_time()
+ my_inst = f - s
+ # print "Instrumented =", my_inst
+ avg_cost = (my_inst - my_simple)/m
+ #print "Delta/call =", avg_cost, "(profiler fixup constant)"
+ return avg_cost
+
+ # simulate a program with no profiler activity
+ def simple(self):
+ a = 1
+ pass
+
+ # simulate a program with call/return event processing
+ def instrumented(self):
+ a = 1
+ self.profiler_simulation(a, a, a)
+
+ # simulate an event processing activity (from user's perspective)
+ def profiler_simulation(self, x, y, z):
+ t = self.timer()
+ ## t = t[0] + t[1]
+ self.ut = t
class OldProfile(Profile):
- """A derived profiler that simulates the old style profile, providing
- errant results on recursive functions. The reason for the usefulness of
- this profiler is that it runs faster (i.e., less overhead). It still
- creates all the caller stats, and is quite useful when there is *no*
- recursion in the user's code.
-
- This code also shows how easy it is to create a modified profiler.
- """
+ """A derived profiler that simulates the old style profile, providing
+ errant results on recursive functions. The reason for the usefulness of
+ this profiler is that it runs faster (i.e., less overhead). It still
+ creates all the caller stats, and is quite useful when there is *no*
+ recursion in the user's code.
- def trace_dispatch_exception(self, frame, t):
- rt, rtt, rct, rfn, rframe, rcur = self.cur
- if rcur and not rframe is frame:
- return self.trace_dispatch_return(rframe, t)
- return 0
+ This code also shows how easy it is to create a modified profiler.
+ """
- def trace_dispatch_call(self, frame, t):
- fn = `frame.f_code`
-
- self.cur = (t, 0, 0, fn, frame, self.cur)
- if self.timings.has_key(fn):
- tt, ct, callers = self.timings[fn]
- self.timings[fn] = tt, ct, callers
- else:
- self.timings[fn] = 0, 0, {}
- return 1
+ def trace_dispatch_exception(self, frame, t):
+ rt, rtt, rct, rfn, rframe, rcur = self.cur
+ if rcur and not rframe is frame:
+ return self.trace_dispatch_return(rframe, t)
+ return 0
- def trace_dispatch_return(self, frame, t):
- rt, rtt, rct, rfn, frame, rcur = self.cur
- rtt = rtt + t
- sft = rtt + rct
+ def trace_dispatch_call(self, frame, t):
+ fn = `frame.f_code`
- pt, ptt, pct, pfn, pframe, pcur = rcur
- self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
+ self.cur = (t, 0, 0, fn, frame, self.cur)
+ if self.timings.has_key(fn):
+ tt, ct, callers = self.timings[fn]
+ self.timings[fn] = tt, ct, callers
+ else:
+ self.timings[fn] = 0, 0, {}
+ return 1
- tt, ct, callers = self.timings[rfn]
- if callers.has_key(pfn):
- callers[pfn] = callers[pfn] + 1
- else:
- callers[pfn] = 1
- self.timings[rfn] = tt+rtt, ct + sft, callers
+ def trace_dispatch_return(self, frame, t):
+ rt, rtt, rct, rfn, frame, rcur = self.cur
+ rtt = rtt + t
+ sft = rtt + rct
- return 1
+ pt, ptt, pct, pfn, pframe, pcur = rcur
+ self.cur = pt, ptt+rt, pct+sft, pfn, pframe, pcur
+
+ tt, ct, callers = self.timings[rfn]
+ if callers.has_key(pfn):
+ callers[pfn] = callers[pfn] + 1
+ else:
+ callers[pfn] = 1
+ self.timings[rfn] = tt+rtt, ct + sft, callers
+
+ return 1
- def snapshot_stats(self):
- self.stats = {}
- for func in self.timings.keys():
- tt, ct, callers = self.timings[func]
- callers = callers.copy()
- nc = 0
- for func_caller in callers.keys():
- nc = nc + callers[func_caller]
- self.stats[func] = nc, nc, tt, ct, callers
+ def snapshot_stats(self):
+ self.stats = {}
+ for func in self.timings.keys():
+ tt, ct, callers = self.timings[func]
+ callers = callers.copy()
+ nc = 0
+ for func_caller in callers.keys():
+ nc = nc + callers[func_caller]
+ self.stats[func] = nc, nc, tt, ct, callers
-
+
class HotProfile(Profile):
- """The fastest derived profile example. It does not calculate
- caller-callee relationships, and does not calculate cumulative
- time under a function. It only calculates time spent in a
- function, so it runs very quickly due to its very low overhead.
- """
+ """The fastest derived profile example. It does not calculate
+ caller-callee relationships, and does not calculate cumulative
+ time under a function. It only calculates time spent in a
+ function, so it runs very quickly due to its very low overhead.
+ """
- def trace_dispatch_exception(self, frame, t):
- rt, rtt, rfn, rframe, rcur = self.cur
- if rcur and not rframe is frame:
- return self.trace_dispatch_return(rframe, t)
- return 0
+ def trace_dispatch_exception(self, frame, t):
+ rt, rtt, rfn, rframe, rcur = self.cur
+ if rcur and not rframe is frame:
+ return self.trace_dispatch_return(rframe, t)
+ return 0
- def trace_dispatch_call(self, frame, t):
- self.cur = (t, 0, frame, self.cur)
- return 1
+ def trace_dispatch_call(self, frame, t):
+ self.cur = (t, 0, frame, self.cur)
+ return 1
- def trace_dispatch_return(self, frame, t):
- rt, rtt, frame, rcur = self.cur
+ def trace_dispatch_return(self, frame, t):
+ rt, rtt, frame, rcur = self.cur
- rfn = `frame.f_code`
+ rfn = `frame.f_code`
- pt, ptt, pframe, pcur = rcur
- self.cur = pt, ptt+rt, pframe, pcur
+ pt, ptt, pframe, pcur = rcur
+ self.cur = pt, ptt+rt, pframe, pcur
- if self.timings.has_key(rfn):
- nc, tt = self.timings[rfn]
- self.timings[rfn] = nc + 1, rt + rtt + tt
- else:
- self.timings[rfn] = 1, rt + rtt
+ if self.timings.has_key(rfn):
+ nc, tt = self.timings[rfn]
+ self.timings[rfn] = nc + 1, rt + rtt + tt
+ else:
+ self.timings[rfn] = 1, rt + rtt
- return 1
+ return 1
- def snapshot_stats(self):
- self.stats = {}
- for func in self.timings.keys():
- nc, tt = self.timings[func]
- self.stats[func] = nc, nc, tt, 0, {}
+ def snapshot_stats(self):
+ self.stats = {}
+ for func in self.timings.keys():
+ nc, tt = self.timings[func]
+ self.stats[func] = nc, nc, tt, 0, {}
-
+
#****************************************************************************
def Stats(*args):
- print 'Report generating functions are in the "pstats" module\a'
+ print 'Report generating functions are in the "pstats" module\a'
# When invoked as main program, invoke the profiler on a script
if __name__ == '__main__':
- import sys
- import os
- if not sys.argv[1:]:
- print "usage: profile.py scriptfile [arg] ..."
- sys.exit(2)
+ import sys
+ import os
+ if not sys.argv[1:]:
+ print "usage: profile.py scriptfile [arg] ..."
+ sys.exit(2)
- filename = sys.argv[1] # Get script filename
+ filename = sys.argv[1] # Get script filename
- del sys.argv[0] # Hide "profile.py" from argument list
+ del sys.argv[0] # Hide "profile.py" from argument list
- # Insert script directory in front of module search path
- sys.path.insert(0, os.path.dirname(filename))
+ # Insert script directory in front of module search path
+ sys.path.insert(0, os.path.dirname(filename))
- run('execfile(' + `filename` + ')')
+ run('execfile(' + `filename` + ')')