Simple script which calculates time spent in a function. The function which is being timed should be decorated with @timing. Keeps track of stack, if children have an @timing, they are also included in the output

timing.py

timing_indent = -1
call_graph = list()

def timing(f):
    def wrap(*args, **kwargs):

        global timing_indent
        global call_graph

        timing_indent += 1

        filename = f.func_code.co_filename.split('/')[-1]
        call_graph.append([timing_indent, filename, f.func_name, 0, args])
        idx = len(call_graph) - 1

        time1 = time.time()

        try:
            ret = f(*args, **kwargs)
        finally:

            time2 = time.time()
            dt = (time2 - time1) * 1000.0
            #update the time
            call_graph[idx][3] = dt

            if timing_indent == 0:
                while len(call_graph):
                    m = call_graph.pop(0)
                    mesg = '\t'* m[0] + "[%s:%s]%0.3f" % (m[1], m[2], m[3])
                    #if m[2] == "doexec":
                    #    mesg += str(m[4])

                    logging.warning(mesg)

            timing_indent -= 1

        return ret

    return wrap