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 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        timings[rfn] = cc, ns - 1, tt + rit, ct, callers        return 1    dispatch = {        "call": trace_dispatch_call,        "exception": trace_dispatch_exception,        "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):        import pstats        pstats.Stats(self).strip_dirs().sort_stats(-1). \                  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 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 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(`func`)        sys.setprofile(self.dispatcher)        try:            return apply(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'# When invoked as main program, invoke the profiler on a scriptif __name__ == '__main__':    if not sys.argv[1:]:        print "usage: profile.py scriptfile [arg] ..."        sys.exit(2)    filename = sys.argv[1]  # Get script filename    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))    run('execfile(' + `filename` + ')')