Time all your functions with this simple decorator — Python

Since I’m a data scientist at an NLP startup, I noticed that most of my colleagues were writing duplicate lines of code to time their functions or class methods. On top of that, they were using the wrong method to do it.

In this article I’ll show you the standard error, what to do instead and finally the snippet of code of the decorator so you can just copy-past it in your code to time all your functions.

Simple example:

import time
def func_sleep():
    start = time.time()
    time.sleep(5)
    end = time.time()
    print("Import - Done : in" + str(start - end) + " sec")
func_sleep() ## Elapsed time-5.003293752670288 sec

First problem:

The first problem here the use of time.time() to mesure elapsed time during func_sleep. Indeed time() method of Time module returns the time as a floating point number expressed in seconds since the epoch, in UTC. Even though the time is always returned as a floating point number, not all systems provide time with a better precision than 1 second.

time.time() gave extremely varied result across different runs (2s vs 10s) in a windows laptop, which I believe was due to CPU throttling.

So it is not really suitable to get the time complexity of your function. We should rather use time.perf_counter() or time.process_time() depending on your use case.

perf_counter() should measure the real amount of time for a process to take, as if you used a stop watch.

process_time() will give you the time spent by the computer for the current process, a computer with an OS usually won’t spend 100% of the time on any given process. This counter shouldn’t count the time the cpu is running anything else.

Most cases perf_counter is probably preferable but process_time can be useful if you want to compare code efficiency.

One example worth 1000 words so :

• perf_counter:

def func_sleep_perf_counter():
    start = time.perf_counter()
    time.sleep(5)
    end = time.perf_counter()
    print("Import - Done : " + str(start - end) + " sec")
func_sleep_perf_counter() // Elapsed time-5.0023572370409966 sec

• process_time:

def func_sleep_process_time():
    start = time.process_time()
    time.sleep(5)
    end = time.perf_counter()
    print("Elapsed time" + str(start - end) + " sec")
func_sleep_process_time() // Elapsed time-9505590.512610989 sec

As we can see, process_time did not take into account the time taken during time.sleep() because sleep blocks the thread and process_time only takes into account the time taken by the processor.

Second problem:

The second problem is that we have to write these few lines of code on each function whose elapsed time we want to measure. This makes your code less clean and it takes you more time to write the same lines of code each time.

Solution:

The solution is simple. It consists in using a decorator that allows us to write the time only once in a .py file and to use it as many times as we want by simply adding a line of code.

def func_sleep_perf_counter(func):
    @wraps(func)  # improves debugging
    def wrapper(*arg):
        start = time.perf_counter()  # needs python3.3 or higher
        result = func(*arg)
        end = time.perf_counter()
        fs = '{} took {:.3f} seconds'
        print(fs.format(func.__name__, (end - start)))
        return result
    return wrapper
@print_timing
def func_sleep_perf_counter():
    time.sleep(5)
func_sleep_perf_counter() //func_sleep_process_time took 5.004 seconds
@print_timing
def func_simple_loop():
    time.sleep(1)
    for i in range(1000):
        j = i*200
func_simple_loop() //func_simple_loop took 1.001 seconds

Isn’t better ?

BONUS:

In case you want to time a method within a class you must declare your decorator as follow:

def print_timing(method):
    '''
    create a timing decorator function
    use
    '''
    @wraps(method)  # improves debugging
    def wrapper(self, *method_args, **method_kwargs):
        start = time.perf_counter()  # needs python3.3 or higher
        result = method(self, *method_args, **method_kwargs)
        end = time.perf_counter()
        fs = '{} took {:.3f} seconds'
        print(fs.format(method.__name__, (end - start)))
        return result
    return wrapper

and just like functions decleare @print_timing on top of your methods.

Thank you all for reading my first post. If you are interesting by tips like this to write a better python don’t hesitate to follow my channel. I’ll start to write little posts like this frequently.