Simple time profiling using decorator in Python

If you are writing a simple Python script and want to do time profiling around all the function calls, module CPython can do great job. But you may not want all the depth and preciseness by cPython library but just time profiling around your function.

What do you typically do?

Writing explicit print statements in each function which adds close to 3-4 lines of extra code to your function.

Example,

def func_name1():
    import time
    start = time.time()
    #### function logic here ####
    print("Exec. time :: {} secs".format(time.time() - start))
      
    return value

But what if you have multiple functions?

your time profiling related code is placed redundantly across all the functions. whether you want to profile a function or remove profiling around one, you have to add or remove same set of lines every time. Also, your function logic is shadowed under this code which is just there doing profiling but nothing else.

With multiple functions, you may also want to add function names too for ease of understanding. In Python there is no way you get a function name inside a function unless you use some traceback utility or import inspect (`​inspect.stack()[0][3]`) which is an extra overhead of loading another library into memory.

Simple solution?

Decorator. Create a wrapper function where you can specify formatted message so that your final log will also look consistent. You can dynamically specify function name, choose to do formatting of timestamp and log messages as well. To add or remove a function to time profiling, now you just have to add or remove annotation (decorator) from the function definition.

Example,

def timeit(method):
    def timed(*args, **kw):
        start = time.time()
        result = method(*args, **kw)
        print(" ** function : {0}  ends.  Execution time :: {1} secs"
              "".format(method.__name__, time.time() - start))
        return result
    return timed

Now, you can simply decorate your function.

@timeit
def func_name1():
    #### function logic here ####    
    return value

Please suggest your preferred ways. Thanks for reading.