Use function annotation to track elapsed execution time (Python recipe) by John Pywtorak

ActiveState Code (http://code.activestate.com/recipes/440573/)

Re: Use function annotation to track elapsed execution time. Here's a slight extension that will give you the min, max, and average time spent in a function. It might be useful for very simplistic profiling.

def timeit(f):
    """ Annotate a function with its elapsed execution time. """
    def timed_f(*args, **kwargs):
        t1 = time.time()

        try:
            f(*args, **kwargs)
        finally:
            t2 = time.time()

        dt = t2-t1
        timed_f.func_maxtime = max(dt, getattr(timed_f, 'func_maxtime', 0))
        timed_f.func_mintime = min(dt, getattr(timed_f, 'func_mintime',
                                               sys.maxint))
        timed_f.func_numcalls = getattr(timed_f, 'func_numcalls',0)+1
        timed_f.func_avgtime = ((dt+((timed_f.func_numcalls-1) *
                                     getattr(timed_f, 'func_avgtime',0))) /
                                timed_f.func_numcalls)

    return timed_f

def print_functimes(f):
    print 'Avg running time: %f secs' % f.func_avgtime
    print 'Max running time: %f secs' % f.func_maxtime
    print 'Min running time: %f secs' % f.func_mintime
    print 'Number of calls: %d' % f.func_numcalls

(BTW, to be a friendly decorator, it's probably a good idea to copy the __doc__, __name__, etc attributes from f to timed_f.)

How exactly is this function supposed to be called?

Add a return value to timed_f. The timed_f function doesn't return any value.

Adding a:

res = f(...)

and a

return res

at the end solves the problem of timing a function that returns something.

Below my two cent contribution from using this otherwise very good recipe.

The change allows it to actually pass arguments to the function f and it returns the function timed_f with the tuple func_time as an attribute from which you can extract the actual time in m, s, or ms.

def timeit(f, *args, **kargs):
    def timed_f(args, *kwargs):
        t1 = time.time()
        try:
            f(args, *kwargs)
        finally:
            t2 = time.time()

        timed_f.func_time = ((t2 - t1) / 60.0, t2 - t1, (t2 - t1) * 1000.0)

        if __debug__:
            sys.stdout.write("%s took %0.3fm %0.3fs %0.3fms\n" % (
                f.func_name,
                timed_f.func_time[0],
                timed_f.func_time[1],
                timed_f.func_time[2],
            ))
        return timed_f
    return timed_f(args, *kargs)

For the function that collects statistics here is my modification so I could actually accumulate values:

def timeit2(results, f, *args, **kargs):
    def timed_f(results, f, args, *kwargs):
        t1 = time.time()
        try:
            f(args, *kwargs)
        finally:
            t2 = time.time()
        dt = t2-t1
        timed_f.func_current_exec_time = dt
        if results==None:
            timed_f.func_maxtime = max(dt, getattr(timed_f, 'func_maxtime', 0))
            timed_f.func_mintime = min(dt, getattr(timed_f, 'func_mintime',
                                                   sys.maxint))
            timed_f.func_numcalls = getattr(timed_f, 'func_numcalls',0)+1
            timed_f.func_avgtime = ((dt+((timed_f.func_numcalls-1) *
                                         getattr(timed_f, 'func_avgtime',0))) /
                                    timed_f.func_numcalls)
        else:
            timed_f.func_maxtime = max(dt, results.func_maxtime)
            timed_f.func_mintime = min(dt, results.func_mintime)
            timed_f.func_numcalls = results.func_numcalls+1
            timed_f.func_avgtime = ((dt+((results.func_numcalls)* /
                                    results.func_avgtime)) / 
                                    timed_f.func_numcalls)
    return timed_f
return timed_f(results,f,args,*kargs)

Usage assuming there is a function called FuncToTime() we want quickly profle:

def mytest():
    f=None
    for i in xrange(10):
        f=timeit2(f,FuncToTime)
    print_functimes(f)

If arguments need to be passed just add them like so:

def mytest():
    f=None
    for i in xrange(10):
        f=timeit2(f,FuncToTime, i)
    print_functimes(f)