# Measure the total runtime of a function in a project

I recently wanted to find out which functions take which amount of time in a project, and calling a timer and printing the difference inside a function that is called multiple times does not scale well.

That's why I created my own little decorator function:

from timeit import default_timer as timer

time_in = dict()

def measure(func):

def saveTime(identifier, time):
global time_in
if identifier not in time_in:
time_in[identifier] = 0
time_in[identifier] += time

def measure_wrapper(*args, **kwargs):
global time_in
start = timer()
value = func(*args, **kwargs)
saveTime(func.__name__, timer() - start)
return value

return measure_wrapper



It works by prepending every function (or method) that should be measured with @measure and then printing the dict at the end of the main function. It works as intended. However, it adds a global variable and I'm sure there must already be a solution like it, I just haven't found it.

So, my questions are:

• Is it possible to remove the global variable?
• Is there already a solution like this in the standard libs?
• Are you familiar with cProfile? Jun 7 at 17:20

Is there already a solution like this in the standard libs?

Unless I am misinterpreting what you want exactly, there are profiling tools available in the standard library.

For instance, given the script

def fib(n):
if n == 0:
return 0
elif n == 1:
return 1
else:
return fib(n - 1) + fib(n - 2)

def factorial(n):
if n == 0:
return 1
else:
return n * factorial(n - 1)

def main():
for i in range(30):
fib(i)

for i in range(30):
factorial(i)

if __name__ == '__main__':
main()


you can run:

python -m cProfile test.py


which gives

         4357055 function calls (64 primitive calls) in 1.484 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
1    0.000    0.000    1.484    1.484 test.py:1(<module>)
4356586/30    1.484    0.000    1.484    0.049 test.py:1(fib)
465/30    0.000    0.000    0.000    0.000 test.py:11(factorial)
1    0.000    0.000    1.484    1.484 test.py:18(main)
1    0.000    0.000    1.484    1.484 {built-in method builtins.exec}
1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


This gives a few more statistics than your code currently does. There is also a Python API mentioned in the page that gives a way of using cProfile (or profile) in your python code.

However, if you are more interesting in benchmarks rather than profiling, according to the link above

Note: The profiler modules are designed to provide an execution profile for a given program, not for benchmarking purposes (for that, there is timeit for reasonably accurate results). This particularly applies to benchmarking Python code against C code: the profilers introduce overhead for Python code, but not for C-level functions, and so the C code would seem faster than any Python one.

The already accepted answer by Dair is better than what I am about to write here, however I think there is didactic value in trying to improve the code as written, so consider this a supplementary answer.

First, these smaller changes:

1. Global variables that are not re-assigned inside a function do not require a global declaration.
2. Consider using functools.wraps when writing decorators: this means that for example calling help(func) shows the expected results, rather than showing measure_wrapper.
3. You can simplify your code by using a defaultdict.
from collections import defaultdict
from functools import wraps
from timeit import default_timer as timer

time_in = defaultdict(int)

def measure(func):
@wraps(func)
def measure_wrapper(*args, **kwargs):
start = timer()
value = func(*args, **kwargs)
time_in[func.__name__] += timer() - start
return value

return measure_wrapper


Alright, so how do we use this function?

import mytimer  # or however your module is called

@mytimer.measure
def expensive_func(*args):
...  # do something that takes a lot of time

expensive_func(...)
print(mytimer.time_in['expensive_func'])


Can this be improved? Well, we have a problem in that if we define another expensive_func in a different module, they get counted as the same function, which probably isn't what you want!

A way to improve this is to use the wrapped function to index the dictionary:

        time_in[measure_wrapper] += timer() - start


which you can then use like this:

print(mytimer.time_in[expensive_func])