These files are a subset of the python-2.7.2.tgz distribution from python.org. Changed files from PyMod-2.7.2 have been copied into the corresponding directories of this tree, replacing the original files in the distribution. Signed-off-by: daryl.mcdaniel@intel.com git-svn-id: https://edk2.svn.sourceforge.net/svnroot/edk2/trunk/edk2@13197 6f19259b-4bc3-4df7-8a09-765794883524
		
			
				
	
	
		
			620 lines
		
	
	
		
			24 KiB
		
	
	
	
		
			Python
		
	
	
	
	
	
			
		
		
	
	
			620 lines
		
	
	
		
			24 KiB
		
	
	
	
		
			Python
		
	
	
	
	
	
| #! /usr/bin/env python
 | |
| #
 | |
| # Class for profiling python code. rev 1.0  6/2/94
 | |
| #
 | |
| # Based on prior profile module by Sjoerd Mullender...
 | |
| #   which was hacked somewhat by: Guido van Rossum
 | |
| 
 | |
| """Class for profiling Python code."""
 | |
| 
 | |
| # 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,
 | |
| # provided that the above copyright notice appears in all copies, and
 | |
| # that both that copyright notice and this permission notice appear in
 | |
| # supporting documentation, and that the name of InfoSeek not be used in
 | |
| # advertising or publicity pertaining to distribution of the software
 | |
| # without specific, written prior permission.  This permission is
 | |
| # explicitly restricted to the copying and modification of the software
 | |
| # 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
 | |
| # SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER
 | |
| # RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF
 | |
| # CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN
 | |
| # CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
 | |
| 
 | |
| 
 | |
| 
 | |
| import sys
 | |
| import os
 | |
| import time
 | |
| import marshal
 | |
| from optparse import OptionParser
 | |
| 
 | |
| __all__ = ["run", "runctx", "help", "Profile"]
 | |
| 
 | |
| # Sample timer for use with
 | |
| #i_count = 0
 | |
| #def integer_timer():
 | |
| #       global i_count
 | |
| #       i_count = i_count + 1
 | |
| #       return i_count
 | |
| #itimes = integer_timer # replace with C coded timer returning integers
 | |
| 
 | |
| #**************************************************************************
 | |
| # The following are the static member functions for the profiler class
 | |
| # Note that an instance of Profile() is *not* needed to call them.
 | |
| #**************************************************************************
 | |
| 
 | |
| def run(statement, filename=None, sort=-1):
 | |
|     """Run statement under profiler optionally saving results in filename
 | |
| 
 | |
|     This function takes a single argument that can be passed to the
 | |
|     "exec" statement, and an optional file name.  In all cases this
 | |
|     routine attempts to "exec" its first argument and gather profiling
 | |
|     statistics from the execution. If no file name is present, then this
 | |
|     function automatically prints a simple profiling report, sorted by the
 | |
|     standard name string (file/line/function-name) that is presented in
 | |
|     each line.
 | |
|     """
 | |
|     prof = Profile()
 | |
|     try:
 | |
|         prof = prof.run(statement)
 | |
|     except SystemExit:
 | |
|         pass
 | |
|     if filename is not None:
 | |
|         prof.dump_stats(filename)
 | |
|     else:
 | |
|         return prof.print_stats(sort)
 | |
| 
 | |
| def runctx(statement, globals, locals, filename=None, sort=-1):
 | |
|     """Run statement under profiler, supplying your own globals and locals,
 | |
|     optionally saving results in filename.
 | |
| 
 | |
|     statement and filename have the same semantics as profile.run
 | |
|     """
 | |
|     prof = Profile()
 | |
|     try:
 | |
|         prof = prof.runctx(statement, globals, locals)
 | |
|     except SystemExit:
 | |
|         pass
 | |
| 
 | |
|     if filename is not None:
 | |
|         prof.dump_stats(filename)
 | |
|     else:
 | |
|         return prof.print_stats(sort)
 | |
| 
 | |
| # Backwards compatibility.
 | |
| def help():
 | |
|     print "Documentation for the profile module can be found "
 | |
|     print "in the Python Library Reference, section 'The Python Profiler'."
 | |
| 
 | |
| if hasattr(os, "times"):
 | |
|     def _get_time_times(timer=os.times):
 | |
|         t = timer()
 | |
|         return t[0] + t[1]
 | |
| 
 | |
| # Using getrusage(3) is better than clock(3) if available:
 | |
| # on some systems (e.g. FreeBSD), getrusage has a higher resolution
 | |
| # Furthermore, on a POSIX system, returns microseconds, which
 | |
| # wrap around after 36min.
 | |
| _has_res = 0
 | |
| try:
 | |
|     import resource
 | |
|     resgetrusage = lambda: resource.getrusage(resource.RUSAGE_SELF)
 | |
|     def _get_time_resource(timer=resgetrusage):
 | |
|         t = timer()
 | |
|         return t[0] + t[1]
 | |
|     _has_res = 1
 | |
| except ImportError:
 | |
|     pass
 | |
| 
 | |
| 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 (frame and previous tuple).  In case an internal error is
 | |
|     detected, the -3 element is used as the function name.
 | |
| 
 | |
|     [ 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 (this latter is tallied in cur[2]).
 | |
|     [ 2] = Total time spent in subfunctions, excluding time executing the
 | |
|            frame's function (this latter is tallied in cur[1]).
 | |
|     [-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).
 | |
| 
 | |
|     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[-3].
 | |
|     The following are the definitions of the members:
 | |
| 
 | |
|     [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.
 | |
|     [4] = A dictionary indicating for each function name, the number of times
 | |
|           it was called by us.
 | |
|     """
 | |
| 
 | |
|     bias = 0  # calibration constant
 | |
| 
 | |
|     def __init__(self, timer=None, bias=None):
 | |
|         self.timings = {}
 | |
|         self.cur = None
 | |
|         self.cmd = ""
 | |
|         self.c_func_name = ""
 | |
| 
 | |
|         if bias is None:
 | |
|             bias = self.bias
 | |
|         self.bias = bias     # Materialize in local dict for lookup speed.
 | |
| 
 | |
|         if not timer:
 | |
|             if _has_res:
 | |
|                 self.timer = resgetrusage
 | |
|                 self.dispatcher = self.trace_dispatch
 | |
|                 self.get_time = _get_time_resource
 | |
|             elif hasattr(time, 'clock'):
 | |
|                 self.timer = self.get_time = time.clock
 | |
|                 self.dispatcher = self.trace_dispatch_i
 | |
|             elif hasattr(os, 'times'):
 | |
|                 self.timer = os.times
 | |
|                 self.dispatcher = self.trace_dispatch
 | |
|                 self.get_time = _get_time_times
 | |
|             else:
 | |
|                 self.timer = self.get_time = time.time
 | |
|                 self.dispatcher = self.trace_dispatch_i
 | |
|         else:
 | |
|             self.timer = timer
 | |
|             t = self.timer() # test out timer function
 | |
|             try:
 | |
|                 length = len(t)
 | |
|             except TypeError:
 | |
|                 self.get_time = timer
 | |
|                 self.dispatcher = self.trace_dispatch_i
 | |
|             else:
 | |
|                 if length == 2:
 | |
|                     self.dispatcher = self.trace_dispatch
 | |
|                 else:
 | |
|                     self.dispatcher = self.trace_dispatch_l
 | |
|                 # This get_time() implementation needs to be defined
 | |
|                 # here to capture the passed-in timer in the parameter
 | |
|                 # list (for performance).  Note that we can't assume
 | |
|                 # the timer() result contains two values in all
 | |
|                 # cases.
 | |
|                 def get_time_timer(timer=timer, sum=sum):
 | |
|                     return sum(timer())
 | |
|                 self.get_time = get_time_timer
 | |
|         self.t = self.get_time()
 | |
|         self.simulate_call('profiler')
 | |
| 
 | |
|     # Heavily optimized dispatch routine for os.times() timer
 | |
| 
 | |
|     def trace_dispatch(self, frame, event, arg):
 | |
|         timer = self.timer
 | |
|         t = timer()
 | |
|         t = t[0] + t[1] - self.t - self.bias
 | |
| 
 | |
|         if event == "c_call":
 | |
|             self.c_func_name = arg.__name__
 | |
| 
 | |
|         if self.dispatch[event](self, frame,t):
 | |
|             t = timer()
 | |
|             self.t = t[0] + t[1]
 | |
|         else:
 | |
|             r = timer()
 | |
|             self.t = r[0] + r[1] - t # put back unrecorded delta
 | |
| 
 | |
|     # Dispatch routine for best timer program (return = scalar, fastest if
 | |
|     # an integer but float works too -- and time.clock() relies on that).
 | |
| 
 | |
|     def trace_dispatch_i(self, frame, event, arg):
 | |
|         timer = self.timer
 | |
|         t = timer() - self.t - self.bias
 | |
| 
 | |
|         if event == "c_call":
 | |
|             self.c_func_name = arg.__name__
 | |
| 
 | |
|         if self.dispatch[event](self, frame, t):
 | |
|             self.t = timer()
 | |
|         else:
 | |
|             self.t = timer() - t  # put back unrecorded delta
 | |
| 
 | |
|     # Dispatch routine for macintosh (timer returns time in ticks of
 | |
|     # 1/60th second)
 | |
| 
 | |
|     def trace_dispatch_mac(self, frame, event, arg):
 | |
|         timer = self.timer
 | |
|         t = timer()/60.0 - self.t - self.bias
 | |
| 
 | |
|         if event == "c_call":
 | |
|             self.c_func_name = arg.__name__
 | |
| 
 | |
|         if self.dispatch[event](self, frame, t):
 | |
|             self.t = timer()/60.0
 | |
|         else:
 | |
|             self.t = timer()/60.0 - t  # put back unrecorded delta
 | |
| 
 | |
|     # SLOW generic dispatch routine for timer returning lists of numbers
 | |
| 
 | |
|     def trace_dispatch_l(self, frame, event, arg):
 | |
|         get_time = self.get_time
 | |
|         t = get_time() - self.t - self.bias
 | |
| 
 | |
|         if event == "c_call":
 | |
|             self.c_func_name = arg.__name__
 | |
| 
 | |
|         if self.dispatch[event](self, frame, t):
 | |
|             self.t = get_time()
 | |
|         else:
 | |
|             self.t = get_time() - t # put back unrecorded delta
 | |
| 
 | |
|     # In the event handlers, the first 3 elements of self.cur are unpacked
 | |
|     # into vrbls w/ 3-letter names.  The last two characters are meant to be
 | |
|     # mnemonic:
 | |
|     #     _pt  self.cur[0] "parent time"   time to be charged to parent frame
 | |
|     #     _it  self.cur[1] "internal time" time spent directly in the function
 | |
|     #     _et  self.cur[2] "external time" time spent in subfunctions
 | |
| 
 | |
|     def trace_dispatch_exception(self, frame, t):
 | |
|         rpt, rit, ret, rfn, rframe, rcur = self.cur
 | |
|         if (rframe is not frame) and rcur:
 | |
|             return self.trace_dispatch_return(rframe, t)
 | |
|         self.cur = rpt, rit+t, ret, rfn, rframe, rcur
 | |
|         return 1
 | |
| 
 | |
| 
 | |
|     def trace_dispatch_call(self, frame, t):
 | |
|         if self.cur and frame.f_back is not self.cur[-2]:
 | |
|             rpt, rit, ret, rfn, rframe, rcur = self.cur
 | |
|             if not isinstance(rframe, Profile.fake_frame):
 | |
|                 assert rframe.f_back is frame.f_back, ("Bad call", rfn,
 | |
|                                                        rframe, rframe.f_back,
 | |
|                                                        frame, frame.f_back)
 | |
|                 self.trace_dispatch_return(rframe, 0)
 | |
|                 assert (self.cur is None or \
 | |
|                         frame.f_back is self.cur[-2]), ("Bad call",
 | |
|                                                         self.cur[-3])
 | |
|         fcode = frame.f_code
 | |
|         fn = (fcode.co_filename, fcode.co_firstlineno, fcode.co_name)
 | |
|         self.cur = (t, 0, 0, fn, frame, self.cur)
 | |
|         timings = self.timings
 | |
|         if fn in timings:
 | |
|             cc, ns, tt, ct, callers = timings[fn]
 | |
|             timings[fn] = cc, ns + 1, tt, ct, callers
 | |
|         else:
 | |
|             timings[fn] = 0, 0, 0, 0, {}
 | |
|         return 1
 | |
| 
 | |
|     def trace_dispatch_c_call (self, frame, t):
 | |
|         fn = ("", 0, self.c_func_name)
 | |
|         self.cur = (t, 0, 0, fn, frame, self.cur)
 | |
|         timings = self.timings
 | |
|         if fn in timings:
 | |
|             cc, ns, tt, ct, callers = timings[fn]
 | |
|             timings[fn] = cc, ns+1, tt, ct, callers
 | |
|         else:
 | |
|             timings[fn] = 0, 0, 0, 0, {}
 | |
|         return 1
 | |
| 
 | |
|     def trace_dispatch_return(self, frame, t):
 | |
|         if frame is not self.cur[-2]:
 | |
|             assert frame is self.cur[-2].f_back, ("Bad return", self.cur[-3])
 | |
|             self.trace_dispatch_return(self.cur[-2], 0)
 | |
| 
 | |
|         # Prefix "r" means part of the Returning or exiting frame.
 | |
|         # Prefix "p" means part of the Previous or Parent or older frame.
 | |
| 
 | |
|         rpt, rit, ret, rfn, frame, rcur = self.cur
 | |
|         rit = rit + t
 | |
|         frame_total = rit + ret
 | |
| 
 | |
|         ppt, pit, pet, pfn, pframe, pcur = rcur
 | |
|         self.cur = ppt, pit + rpt, pet + frame_total, pfn, pframe, pcur
 | |
| 
 | |
|         timings = self.timings
 | |
|         cc, ns, tt, ct, callers = timings[rfn]
 | |
|         if not ns:
 | |
|             # This is the only occurrence of the function on the stack.
 | |
|             # Else this is a (directly or indirectly) recursive call, and
 | |
|             # its cumulative time will get updated when the topmost call to
 | |
|             # it returns.
 | |
|             ct = ct + frame_total
 | |
|             cc = cc + 1
 | |
| 
 | |
|         if pfn in callers:
 | |
|             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
 | |
| 
 | |
|         timings[rfn] = cc, ns - 1, tt + rit, ct, callers
 | |
| 
 | |
|         return 1
 | |
| 
 | |
| 
 | |
|     dispatch = {
 | |
|         "call": trace_dispatch_call,
 | |
|         "exception": trace_dispatch_exception,
 | |
|         "return": trace_dispatch_return,
 | |
|         "c_call": trace_dispatch_c_call,
 | |
|         "c_exception": trace_dispatch_return,  # the C function returned
 | |
|         "c_return": trace_dispatch_return,
 | |
|         }
 | |
| 
 | |
| 
 | |
|     # The next few functions 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)
 | |
| 
 | |
|     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))
 | |
| 
 | |
|     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)
 | |
|         self.dispatch['call'](self, frame, 0)
 | |
| 
 | |
|     # collect stats from pending stack, including getting final
 | |
|     # timings for self.cmd frame.
 | |
| 
 | |
|     def simulate_cmd_complete(self):
 | |
|         get_time = self.get_time
 | |
|         t = get_time() - self.t
 | |
|         while self.cur[-1]:
 | |
|             # We *can* cause assertion errors here if
 | |
|             # dispatch_trace_return checks for a frame match!
 | |
|             self.dispatch['return'](self, self.cur[-2], t)
 | |
|             t = 0
 | |
|         self.t = get_time() - t
 | |
| 
 | |
| 
 | |
|     def print_stats(self, sort=-1):
 | |
|         import pstats
 | |
|         pstats.Stats(self).strip_dirs().sort_stats(sort). \
 | |
|                   print_stats()
 | |
| 
 | |
|     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, (cc, ns, tt, ct, callers) in self.timings.iteritems():
 | |
|             callers = callers.copy()
 | |
|             nc = 0
 | |
|             for callcnt in callers.itervalues():
 | |
|                 nc += callcnt
 | |
|             self.stats[func] = cc, nc, tt, ct, callers
 | |
| 
 | |
| 
 | |
|     # 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
 | |
| 
 | |
|     # This method is more useful to profile a single function call.
 | |
|     def runcall(self, func, *args, **kw):
 | |
|         self.set_cmd(repr(func))
 | |
|         sys.setprofile(self.dispatcher)
 | |
|         try:
 | |
|             return func(*args, **kw)
 | |
|         finally:
 | |
|             sys.setprofile(None)
 | |
| 
 | |
| 
 | |
|     #******************************************************************
 | |
|     # 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.
 | |
|     #
 | |
|     # 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.)
 | |
|     #**************************************************************
 | |
| 
 | |
|     def calibrate(self, m, verbose=0):
 | |
|         if self.__class__ is not Profile:
 | |
|             raise TypeError("Subclasses must override .calibrate().")
 | |
| 
 | |
|         saved_bias = self.bias
 | |
|         self.bias = 0
 | |
|         try:
 | |
|             return self._calibrate_inner(m, verbose)
 | |
|         finally:
 | |
|             self.bias = saved_bias
 | |
| 
 | |
|     def _calibrate_inner(self, m, verbose):
 | |
|         get_time = self.get_time
 | |
| 
 | |
|         # Set up a test case to be run with and without profiling.  Include
 | |
|         # lots of calls, because we're trying to quantify stopwatch overhead.
 | |
|         # Do not raise any exceptions, though, because we want to know
 | |
|         # exactly how many profile events are generated (one call event, +
 | |
|         # one return event, per Python-level call).
 | |
| 
 | |
|         def f1(n):
 | |
|             for i in range(n):
 | |
|                 x = 1
 | |
| 
 | |
|         def f(m, f1=f1):
 | |
|             for i in range(m):
 | |
|                 f1(100)
 | |
| 
 | |
|         f(m)    # warm up the cache
 | |
| 
 | |
|         # elapsed_noprofile <- time f(m) takes without profiling.
 | |
|         t0 = get_time()
 | |
|         f(m)
 | |
|         t1 = get_time()
 | |
|         elapsed_noprofile = t1 - t0
 | |
|         if verbose:
 | |
|             print "elapsed time without profiling =", elapsed_noprofile
 | |
| 
 | |
|         # elapsed_profile <- time f(m) takes with profiling.  The difference
 | |
|         # is profiling overhead, only some of which the profiler subtracts
 | |
|         # out on its own.
 | |
|         p = Profile()
 | |
|         t0 = get_time()
 | |
|         p.runctx('f(m)', globals(), locals())
 | |
|         t1 = get_time()
 | |
|         elapsed_profile = t1 - t0
 | |
|         if verbose:
 | |
|             print "elapsed time with profiling =", elapsed_profile
 | |
| 
 | |
|         # reported_time <- "CPU seconds" the profiler charged to f and f1.
 | |
|         total_calls = 0.0
 | |
|         reported_time = 0.0
 | |
|         for (filename, line, funcname), (cc, ns, tt, ct, callers) in \
 | |
|                 p.timings.items():
 | |
|             if funcname in ("f", "f1"):
 | |
|                 total_calls += cc
 | |
|                 reported_time += tt
 | |
| 
 | |
|         if verbose:
 | |
|             print "'CPU seconds' profiler reported =", reported_time
 | |
|             print "total # calls =", total_calls
 | |
|         if total_calls != m + 1:
 | |
|             raise ValueError("internal error: total calls = %d" % total_calls)
 | |
| 
 | |
|         # reported_time - elapsed_noprofile = overhead the profiler wasn't
 | |
|         # able to measure.  Divide by twice the number of calls (since there
 | |
|         # are two profiler events per call in this test) to get the hidden
 | |
|         # overhead per event.
 | |
|         mean = (reported_time - elapsed_noprofile) / 2.0 / total_calls
 | |
|         if verbose:
 | |
|             print "mean stopwatch overhead per profile event =", mean
 | |
|         return mean
 | |
| 
 | |
| #****************************************************************************
 | |
| def Stats(*args):
 | |
|     print 'Report generating functions are in the "pstats" module\a'
 | |
| 
 | |
| def main():
 | |
|     usage = "profile.py [-o output_file_path] [-s sort] scriptfile [arg] ..."
 | |
|     parser = OptionParser(usage=usage)
 | |
|     parser.allow_interspersed_args = False
 | |
|     parser.add_option('-o', '--outfile', dest="outfile",
 | |
|         help="Save stats to <outfile>", default=None)
 | |
|     parser.add_option('-s', '--sort', dest="sort",
 | |
|         help="Sort order when printing to stdout, based on pstats.Stats class",
 | |
|         default=-1)
 | |
| 
 | |
|     if not sys.argv[1:]:
 | |
|         parser.print_usage()
 | |
|         sys.exit(2)
 | |
| 
 | |
|     (options, args) = parser.parse_args()
 | |
|     sys.argv[:] = args
 | |
| 
 | |
|     if len(args) > 0:
 | |
|         progname = args[0]
 | |
|         sys.path.insert(0, os.path.dirname(progname))
 | |
|         with open(progname, 'rb') as fp:
 | |
|             code = compile(fp.read(), progname, 'exec')
 | |
|         globs = {
 | |
|             '__file__': progname,
 | |
|             '__name__': '__main__',
 | |
|             '__package__': None,
 | |
|         }
 | |
|         runctx(code, globs, None, options.outfile, options.sort)
 | |
|     else:
 | |
|         parser.print_usage()
 | |
|     return parser
 | |
| 
 | |
| # When invoked as main program, invoke the profiler on a script
 | |
| if __name__ == '__main__':
 | |
|     main()
 |