Given a function like:
do_something_big():
do_1()
do_2()
do_3()
It's easy to get the time it takes to run either do_something_big() or a single instance of do_1(). But assuming I have:
for _ in range(100000):
do_something_big()
Is there an easy way to get how long 100,000 do_1's took? It's not so difficult to do - you'd just time each one and update some global state to keep track of aggregate time. But is there a utility already built that abstracts this for me?
I would suggest using e.g. cProfile. This package will time each function in your code and output on a nice format:
import cProfile
pr = cProfile.Profile()
pr.enable()
run_your_program_here()
pr.disable()
pr.print_stats(sort='tottime')
The sort argument in the last line will sort the output based on your given option. You can read more about it here:
ncalls – how many times the function/method has been called (in case the same function/method is being called recursively then ncalls has two values eg. 120/20, where the first is the true number of calls, while the second is the number of direct calls)
tottime – the total time in seconds excluding the time of other functions/methods
percall – average time to execute function (per call)
cumtime – the total time in seconds includes the times of other functions it calls
percall – similar to the previous percall, however this one includes network delays thread sleeps etc…
In your case I would use 'tottime' and look at how much time do_1 took.
This is a decorator as the utility that you are looking for. Inspiration from here and here.
We create a decorator @timeit. We annotate our methods with this decorator which takes an optional n parameter. When n invocations reached, print a time metric for this method, otherwise print on every invocation.
from functools import wraps
from time import time
from collections import defaultdict
timedata = defaultdict(lambda : (0, 0.0))
def timeit(*decArgs, **decKw):
def _timeit(func):
@wraps(func)
def timed(*args, **kw):
name = func.__name__.upper()
n = decKw.get('n', 1)
if timedata[name][0] >= n:
return func(*args, **kw)
ts = time()
result = func(*args, **kw)
te = time()
duration = int((te - ts) * 1000)
cnt, ave = timedata[name]
cnt += 1
timedata[name] = (cnt, ((cnt-1) * ave + duration) / cnt)
if n == cnt:
print(f'{name:30s}: [{n:6d}x] -> {ave*cnt:7.3f}ms ({ave:6.3f}ms ave)')
timedata[name] = (0, 0.0)
return result
return timed
return _timeit
Usage:
from random import random
@timeit(n=100)
def do_1():
sleep(random()/1000)
@timeit(n=3)
def do_something_big():
for _ in range(200):
do_1()
for _ in range(5):
do_something_big()
Output:
DO_1 : [ 100x] -> 19.192ms ( 0.192ms ave)
DO_1 : [ 100x] -> 23.232ms ( 0.232ms ave)
DO_1 : [ 100x] -> 24.242ms ( 0.242ms ave)
DO_1 : [ 100x] -> 18.182ms ( 0.182ms ave)
DO_1 : [ 100x] -> 14.141ms ( 0.141ms ave)
DO_1 : [ 100x] -> 23.232ms ( 0.232ms ave)
DO_SOMETHING_BIG : [ 3x] -> 393.000ms (131.000ms ave)
DO_1 : [ 100x] -> 27.273ms ( 0.273ms ave)
DO_1 : [ 100x] -> 22.222ms ( 0.222ms ave)
DO_1 : [ 100x] -> 21.212ms ( 0.212ms ave)
DO_1 : [ 100x] -> 24.242ms ( 0.242ms ave)
Here is what I found on internet https://realpython.com/python-timer/: you’ll add optional names to your Python timer. You can use the name for two different purposes:
Looking up the elapsed time later in your code Accumulating timers with the same name To add names to your Python timer, you need to make two more changes to timer.py. First, Timer should accept the name as a parameter. Second, the elapsed time should be added to .timers when a timer stops:
class Timer: timers = dict()
def __init__(
self,
name=None,
text="Elapsed time: {:0.4f} seconds",
logger=print,
):
self._start_time = None
self.name = name
self.text = text
self.logger = logger
# Add new named timers to dictionary of timers
if name:
self.timers.setdefault(name, 0)
# Other methods are unchanged
def stop(self):
"""Stop the timer, and report the elapsed time"""
if self._start_time is None:
raise TimerError(f"Timer is not running. Use .start() to start it")
elapsed_time = time.perf_counter() - self._start_time
self._start_time = None
if self.logger:
self.logger(self.text.format(elapsed_time))
if self.name:
self.timers[self.name] += elapsed_time
return elapsed_time
Note that you use .setdefault() when adding the new Python timer to .timers. This is a great feature that only sets the value if name is not already defined in the dictionary. If name is already used in .timers, then the value is left untouched. This allows you to accumulate several timers:
>>> from timer import Timer
>>> t = Timer("accumulate")
>>> t.start()
>>> t.stop() # A few seconds later
Elapsed time: 3.7036 seconds
3.703554293999332
>>> t.start()
>>> t.stop() # A few seconds later
Elapsed time: 2.3449 seconds
2.3448921170001995
>>> Timer.timers
{'accumulate': 6.0484464109995315}
