Simplify logging of timings of selected parts of an application.
Contents
Recommended initialization is as follows.
import timing
_TIME = timing.get_timing_group(__name__) # type: timing.TimingGroupThis follows the conventions of logging module.
import logging
_LOG = logging.getLogger(__name__)Any name can be used instead of __name__.
However, if names of format module.sub.sub_sub are used, this will create a timing
hierarchy where each timing data is stored in its proper location and can be queried easier.
The resulting _TIME object is used to create individual timers,
and will handle storing results in cache, which later can be used to obtain timing statistics.
You can obtain the timer object directly via start(name) method.
You'll need to manually call stop() in this case.
timer = _TIME.start('spam') # type: timing.Timing
spam()
more_spam()
timer.stop()You can also obtain the timer object indirectly via measure(name) context manager.
The context manager will take care of calling stop() at the end.
with _TIME.measure('ham') as timer: # type: timing.Timing
ham()
more_ham()And if you want to time many repetitions of the same action (e.g. for statistical significance)
you can use measure_many(name[, samples][, threshold]) generator.
You can decide how many times you want to measure via samples parameter
and how many seconds at most you want to spend on measurements via threshold parameter
for timer in _TIME.measure_many('eggs', samples=1000): # type: timing.Timing
eggs()
more_eggs()
for timer in _TIME.measure_many('bacon', threshold=0.5): # type: timing.Timing
bacon()
more_bacon()
for timer in _TIME.measure_many('tomatoes', samples=500, threshold=0.5): # type: timing.Timing
tomatoes()
more_tomatoes()Also, you can use measure and measure(name) as decorator.
In this scenario you cannot access the timings directly, but the results will be stored
in the timing group object, as well as in the global cache unless you configure the timing
to not use the cache.
import timing
_TIME = timing.get_timing_group(__name__)
@_TIME.measure
def recipe():
ham()
eggs()
bacon()
@_TIME.measure('the_best_recipe')
def bad_recipe():
spam()
spam()
spam()Then, after calling each function the results can be accessed through summary property.
recipe()
bad_recipe()
bad_recipe()
assert _TIME.summary['recipe']['samples'] == 1
assert _TIME.summary['the_best_recipe']['samples'] == 2The summary property is dynamically computed on first access. Subsequent accesses
will not recompute the values, so if you need to access the updated results,
call the summarize() method.
recipe()
assert _TIME.summary['recipe']['samples'] == 1
bad_recipe()
bad_recipe()
assert _TIME.summary['the_best_recipe']['samples'] == 2 # will fail
_TIME.summarize()
assert _TIME.summary['the_best_recipe']['samples'] == 2 # okFurther API and documentation are in development.
See these examples in action in examples.ipynb notebook.
Python version 3.11 or later.
Python libraries as specified in requirements.txt.
Building and running tests additionally requires packages listed in requirements_test.txt.
Tested on Linux, macOS and Windows.