Timing function calls in Python

In [79]:
import time

def time_it(f):
    time_it.active = 0

    def tt(*args, **kwargs):
        time_it.active += 1
        t0 = time.time()
        tabs = '\t'*(time_it.active - 1)
        name = f.__name__
        print('{tabs}Executing <{name}>'.format(tabs=tabs, name=name))
        res = f(*args, **kwargs)
        print('{tabs}Function <{name}> execution time: {time:.3f} seconds'.format(
            tabs=tabs, name=name, time=time.time() - t0))
        time_it.active -= 1
        return res
    return tt
In [80]:
import time
import scipy.ndimage as nd
import numpy as n

@time_it
def do_all(data, blurs):
    for blur in blurs:
        process(data, blur)
        
@time_it
def process(data, amount):
    blurred = nd.gaussian_filter(data, amount)
    out = get_stats(blurred)
    return out

@time_it
def get_stats(c):
    return c.mean(), c.std()
In [10]:
data = n.random.randn(5000,5000)
blurs = n.arange(0,40,10)
In [81]:
do_all(data, blurs)
Executing <do_all>
	Executing <process>
		Executing <get_stats>
		Function <get_stats> execution time: 0.229 seconds
	Function <process> execution time: 0.350 seconds
	Executing <process>
		Executing <get_stats>
		Function <get_stats> execution time: 0.244 seconds
	Function <process> execution time: 3.261 seconds
	Executing <process>
		Executing <get_stats>
		Function <get_stats> execution time: 0.224 seconds
	Function <process> execution time: 5.048 seconds
	Executing <process>
		Executing <get_stats>
		Function <get_stats> execution time: 0.278 seconds
	Function <process> execution time: 6.958 seconds
Function <do_all> execution time: 15.617 seconds