94

I would like to measure the time elapsed to evaluate a block of code in a Python program, possibly separating between user cpu time, system cpu time and elapsed time.

I know the timeit module, but I have many self-written functions and it is not very easy to pass them in the setup process.

I would rather have something that could be used like:

#up to here I have done something....
start_counting() #or whatever command used to mark that I want to measure
                   #the time elapsed in the next rows
# code I want to evaluate
user,system,elapsed = stop_counting() #or whatever command says:
                                      #stop the timer and return the times

The user and system CPU times are not essential (though I would like to measure them), but for the elapsed time I would like to be able to do something like this, rather than using complicated commands or modules.

Martijn Pieters
  • 1,048,767
  • 296
  • 4,058
  • 3,343
lucacerone
  • 9,859
  • 13
  • 52
  • 80

6 Answers6

189

To get the elapsed time in seconds, you can use timeit.default_timer():

import timeit
start_time = timeit.default_timer()
# code you want to evaluate
elapsed = timeit.default_timer() - start_time

timeit.default_timer() is used instead of time.time() or time.clock() because it will choose the timing function that has the higher resolution for any platform.

Andrew Clark
  • 202,379
  • 35
  • 273
  • 306
  • 4
    I have read that this is not the best approach for blocks of code that take only a fraction of second to run. Also I think that using the time module the .clock() method is preferred? http://stackoverflow.com/questions/85451/python-time-clock-vs-time-time-accuracy – lucacerone Mar 29 '13 at 16:26
  • 5
    Changed my answer to use `timeit.default_timer()`, which will choose between `time.time()` or `time.clock()` depending on which has higher resolution on the platform you are using. – Andrew Clark Mar 29 '13 at 17:06
28

I always use a decorator to do some extra work for a existing function, including to get the execution time. It is pythonic and simple.

import time

def time_usage(func):
    def wrapper(*args, **kwargs):
        beg_ts = time.time()
        retval = func(*args, **kwargs)
        end_ts = time.time()
        print("elapsed time: %f" % (end_ts - beg_ts))
        return retval
    return wrapper

@time_usage
def test():
    for i in xrange(0, 10000):
        pass

if __name__ == "__main__":
    test()
Dave X
  • 4,831
  • 4
  • 31
  • 42
Yarkee
  • 9,086
  • 5
  • 28
  • 29
  • 6
    I am sorry, I still don't know how to use decorators :( – lucacerone Mar 29 '13 at 17:32
  • 5
    @LucaCerone there is a excellent explanation about decoration http://stackoverflow.com/questions/739654/understanding-python-decorators . Try to read it patiently and you will understand decorator. – Yarkee Mar 30 '13 at 02:36
  • Maybe add a `retval=...` and `return retval` to the wrapper. If you use the decorator as is, it will discard func's return values. – Dave X Jan 05 '17 at 18:57
13

I found myself solving this problem again and again, so I finally created a library for it. Install with pip install timer_cm. Then:

from time import sleep
from timer_cm import Timer

with Timer('Long task') as timer:
    with timer.child('First step'):
        sleep(1)
    for _ in range(5):
        with timer.child('Baby steps'):
            sleep(.5)

Output:

Long task: 3.520s
  Baby steps: 2.518s (71%)
  First step: 1.001s (28%)
Michael Herrmann
  • 4,832
  • 3
  • 38
  • 53
  • a seemingly relevant question I raised: https://stackoverflow.com/questions/48260833/make-a-child-of-a-timer-cm-timer-object-in-a-called-function – lurix66 Jan 15 '18 at 10:25
  • Works great, except a typo ('import timer' ---> 'import Timer') and a missing package (`import time`) – user3768495 Feb 23 '18 at 22:02
  • That's fantastic. I crated a github issue on your repo with a stub people can use when importing if they want to make it optional. – Craig Ringer Jun 07 '19 at 01:50
11

You can achieve this through the Context Manager, for example:

from contextlib import contextmanager
import time
import logging
@contextmanager
def _log_time_usage(prefix=""):
    '''log the time usage in a code block
    prefix: the prefix text to show
    '''
    start = time.time()
    try:
        yield
    finally:
        end = time.time()
        elapsed_seconds = float("%.2f" % (end - start))
        logging.debug('%s: elapsed seconds: %s', prefix, elapsed_seconds)

use example:

with _log_time_usage("sleep 1: "):
    time.sleep(1)
monklof
  • 161
  • 1
  • 6
1

There is one more option which i loves a lot now for simplicity - ipython. In ipython you got a lot of useful stuff plus:

%time <expression> - to get straight cpu and wall time on expression

%timeit <expression> - to get cpu and wall time in a loop of expression

valex
  • 5,163
  • 2
  • 33
  • 40
0

Python 3 - Simple solution using standard library

Option 1: Triple quote the code

import inspect
import timeit


code_block = inspect.cleandoc("""
    base = 123456789
    exponent = 100
    return base ** exponent
    """)
print(f'\Code block: {timeit.timeit(code_block, number=1, globals=globals())} elapsed seconds')

inspect.cleandoc handles the removal of extra tabs and whitespace so that blocks of code can be copied and pasted without getting indentation errors.

 

Option 2: Place code block in a function

import timeit


def my_function():
    base = 123456789
    exponent = 100
    return base ** exponent


if __name__ == '__main__':
    print(f'With lambda wrapper: {timeit.timeit(lambda: my_function(), number=1)} elapsed seconds')

Note that a function call will add additional execution time versus timing the function body directly.

Christopher Peisert
  • 21,862
  • 3
  • 86
  • 117