From eda3deb84539e5c0e4f92c5893c69a2c5a1b623e Mon Sep 17 00:00:00 2001 From: ancestor-mithril Date: Tue, 30 Apr 2024 22:56:49 +0300 Subject: [PATCH 1/4] Maintaining the args documentation in only 1 place --- timed_decorator/builder.py | 33 +++++++++++++++++++++++++++++++++ timed_decorator/nested_timed.py | 28 ++-------------------------- 2 files changed, 35 insertions(+), 26 deletions(-) create mode 100644 timed_decorator/builder.py diff --git a/timed_decorator/builder.py b/timed_decorator/builder.py new file mode 100644 index 0000000..3c29e69 --- /dev/null +++ b/timed_decorator/builder.py @@ -0,0 +1,33 @@ +from typing import Union + + +def create_timed_decorator(name: str, + nested: bool = True, + collect_gc: bool = True, + disable_gc: bool = False, + use_seconds: bool = False, + precision: int = 9, + show_args: bool = False, + show_kwargs: bool = False, + display_level: int = 1, + sep: str = ', ', + stdout: bool = True, + file_path: Union[str, None] = None, + logger_name: Union[str, None] = None, + return_time: bool = False, + out: dict = None, + use_qualname: bool = False): + """ + Instantiates the timed decorator with a given name. Once instantiated, the timed decorator can be retrieved with + :class:`timed_decorator.builder.get_timed_decorator` and used for measuring the runtime of decorated functions. + + Args: + name (str): The name of the timed decorator which will be instantiated using the provided arguments. Use this + name for retrieving the timed decorator with :class:`timed_decorator.builder.get_timed_decorator`. + nested (bool): If `True`, uses the :class:`timed_decorator.nested_timed.nested_timed` as decorator, otherwise + uses :class:`timed_decorator.simple_timed.timed`. + + See Also: + :class:`timed_decorator.simple_timed.timed` for the remaining parameters' documentation. + """ + pass diff --git a/timed_decorator/nested_timed.py b/timed_decorator/nested_timed.py index 4262746..64ebf7f 100644 --- a/timed_decorator/nested_timed.py +++ b/timed_decorator/nested_timed.py @@ -27,33 +27,9 @@ def nested_timed(collect_gc: bool = True, """ A nested timing decorator that measures the time elapsed during the function call and accounts for other decorators further in the call stack. - It uses perf_counter_ns for measuring which includes time elapsed during sleep and is system-wide. - Args: - collect_gc (bool): If `True`, runs a full garbage collection before timing the wrapped function. Default: - `True`. - disable_gc (bool): If `True`, disabled garbage collection during function execution. Default: `False`. - use_seconds (bool): If `True`, displays the elapsed time in seconds. Default: `False`. - precision (int): Used in conjunction with `use_seconds`, represents the decimal points used for printing - seconds. Default: `9`. - show_args (bool): If `True`, displays the function arguments according to `display_level`. Useful when timing - function calls with arguments of different magnitude. Default: `False`. - show_kwargs (bool): If `True`, displays the keyword arguments according to `display_level`. Default: `False`. - display_level (int): The level of verbosity used when printing function arguments ad keyword arguments. If `0`, - prints the type of the parameters. If `1`, prints values for all primitive types, shapes for arrays, - tensors, dataframes and length for sequences. Otherwise, prints values for all parameters. Default: `1`. - sep (str): The separator used when printing function arguments and keyword arguments. Default: `', '`. - stdout (bool): If `True`, writes the elapsed time to stdout. Default: `True`. - file_path (str): If not `None`, writes the measurement at the end of the given file path. For thread safe - file writing configure use `logger_name` instead. Default: `None`. - logger_name (str): If not `None`, uses the given logger to print the measurement. Can't be used in conjunction - with `file_path`. Default: `None`. - return_time (bool): If `True`, returns the elapsed time in addition to the wrapped function's return value. - Default: `False`. - out (dict): If not `None`, stores the elapsed time in nanoseconds in the given dict using the fully qualified - function name as key. If the key already exists, adds the time to the existing value. Default: `None`. - use_qualname (bool): If `True`, uses the qualified name of the function when logging the elapsed time. Default: - `False`. + See Also: + :class:`timed_decorator.simple_timed.timed` for parameter documentation. """ gc_collect = collect if collect_gc else nop time_formatter = TimeFormatter(use_seconds, precision) From 6018e6eb092cd463cbcecf5a4a147925dfa20b19 Mon Sep 17 00:00:00 2001 From: ancestor-mithril Date: Wed, 1 May 2024 11:23:41 +0300 Subject: [PATCH 2/4] Added methods to register timed decorators and use them afterwards --- timed_decorator/builder.py | 58 ++++++++++++++++++++++++++++++++++++-- 1 file changed, 56 insertions(+), 2 deletions(-) diff --git a/timed_decorator/builder.py b/timed_decorator/builder.py index 3c29e69..afe0199 100644 --- a/timed_decorator/builder.py +++ b/timed_decorator/builder.py @@ -1,5 +1,11 @@ +from functools import wraps from typing import Union +from .nested_timed import nested_timed +from .simple_timed import timed + +_timed_decorators = {} + def create_timed_decorator(name: str, nested: bool = True, @@ -18,7 +24,7 @@ def create_timed_decorator(name: str, out: dict = None, use_qualname: bool = False): """ - Instantiates the timed decorator with a given name. Once instantiated, the timed decorator can be retrieved with + Registers a timed decorator with a given name. Once instantiated, the timed decorator can be retrieved with :class:`timed_decorator.builder.get_timed_decorator` and used for measuring the runtime of decorated functions. Args: @@ -29,5 +35,53 @@ def create_timed_decorator(name: str, See Also: :class:`timed_decorator.simple_timed.timed` for the remaining parameters' documentation. + + """ + global _timed_decorators + if name in _timed_decorators: + raise KeyError(f'Timed decorator {name} already registered.') + + decorator = nested_timed if nested else timed + _timed_decorators[name] = decorator(collect_gc=collect_gc, + disable_gc=disable_gc, + use_seconds=use_seconds, + precision=precision, + show_args=show_args, + show_kwargs=show_kwargs, + display_level=display_level, + sep=sep, + stdout=stdout, + file_path=file_path, + logger_name=logger_name, + return_time=return_time, + out=out, + use_qualname=use_qualname) + + +def _get_timed_decorator(name: str): + global _timed_decorators + if name not in _timed_decorators: + raise KeyError(f'Timed decorator {name} not registered. Please register it first using ' + f'timed_decorator.builder.create_timed_decorator') + + return _timed_decorators[name] + + +def get_timed_decorator(name: str): + """ + Wraps the decorated function and lazily measures its elapsed time using the registered timed decorator. The timer + can be registered after the function definition, but must be registered before the first function call. + + Args: + name (str): The name of the timed decorator registered using + :class:`timed_decorator.builder.create_timed_decorator`. + """ - pass + def decorator(fn): + @wraps(fn) + def wrap(*args, **kwargs): + return _get_timed_decorator(name)(fn)(*args, **kwargs) + + return wrap + + return decorator From 086067384bbc7626b069f034def5a724b9629f19 Mon Sep 17 00:00:00 2001 From: ancestor-mithril Date: Wed, 1 May 2024 11:35:57 +0300 Subject: [PATCH 3/4] Updated documentation --- README.md | 101 +++++++++++++++++++++++++++++++++++++ timed_decorator/builder.py | 4 +- 2 files changed, 103 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index b692c8b..34a0baf 100644 --- a/README.md +++ b/README.md @@ -32,6 +32,8 @@ fibonacci(10000) # fibonacci() -> total time: 1114100ns ``` +For more advanced usage, consider registering a timed decorator and using it afterward through your codebase. See [Registering a timed decorator](#registering-a-timed-decorator). + ### Documentation 1. `timed` @@ -52,6 +54,15 @@ fibonacci(10000) 2. `nested_timed` is similar to `timed`, however it is designed to work nicely with multiple timed functions that call each other, displaying both the total execution time and the difference after subtracting other timed functions on the same call stack. See [Nested timing decorator](#nested-timing-decorator). +3. `create_timed_decorator` registers a timed decorator with a given name. + * `name` (`str`): The name of the timed decorator which will be instantiated using the provided arguments. Use this name for retrieving the timed decorator with `timed_decorator.builder.get_timed_decorator`. + * `nested` (`bool`): If `True`, uses the `timed_decorator.nested_timed.nested_timed` as decorator, otherwise uses `timed_decorator.simple_timed.timed`. Default: `False`. + * Also receives all the other arguments accepted by `timed` and `nested_timed`. + +4. `get_timed_decorator` wraps the decorated function and lazily measures its elapsed time using the registered timed decorator. The timer can be registered after the function definition, but must be registered before the first function call. + * `name` (`str`): The name of the timed decorator registered using `timed_decorator.builder.create_timed_decorator`. + + ### Examples Simple usage. @@ -436,3 +447,93 @@ Prints: batched_euclidean_distance(CpuTensor[10000, 800], CpuTensor[12000, 800]) -> total time: 685659400ns batched_euclidean_distance(CudaTensor[10000, 800], CudaTensor[12000, 800]) -> total time: 260411900ns ``` + + +### Registering a timed decorator + +```py +from time import sleep + +from timed_decorator.builder import create_timed_decorator, get_timed_decorator + + +@get_timed_decorator("MyCustomTimer") +def main(): + @get_timed_decorator("MyCustomTimer") + def function_1(): + sleep(0.1) + + @get_timed_decorator("MyCustomTimer") + def nested_function(): + @get_timed_decorator("MyCustomTimer") + def function_2(): + sleep(0.2) + + @get_timed_decorator("MyCustomTimer") + def function_3(): + sleep(0.3) + + function_2() + function_2() + function_3() + + nested_function() + function_1() + nested_function() + function_1() + + +if __name__ == '__main__': + my_measurements = {} + create_timed_decorator("MyCustomTimer", + collect_gc=False, # I don't want to explicitly collect garbage + disable_gc=True, # I don't want to wait for garbage collection during measuring + stdout=False, # I don't wat to print stuff to console + out=my_measurements # My measurements dict + ) + main() + for key, value in my_measurements.items(): + print(f'Function {key} took {value / 1e+9}s') + print() + print() + + # Now I can do stuff with my measurements. + functions = sorted(my_measurements.keys(), reverse=True) + + for i in range(len(functions)): + fn_1 = functions[i] + print(f'Function {fn_1}:') + for j in range(i + 1, len(functions)): + fn_2 = functions[j] + if fn_1.startswith(fn_2): + ratio = my_measurements[fn_1] / my_measurements[fn_2] * 100 + print(f'* took {ratio:.2f}% from {fn_2}') + print() +``` + +Prints: +``` +Function main..nested_function..function_2 took 0.8016428s +Function main..nested_function..function_3 took 0.6014647s +Function main..nested_function took 1.403586s +Function main..function_1 took 0.2006981s +Function main took 1.6045189s + + +Function main..nested_function..function_3: +* took 42.85% from main..nested_function +* took 37.49% from main + +Function main..nested_function..function_2: +* took 57.11% from main..nested_function +* took 49.96% from main + +Function main..nested_function: +* took 87.48% from main + +Function main..function_1: +* took 12.51% from main + +Function main: + +``` diff --git a/timed_decorator/builder.py b/timed_decorator/builder.py index afe0199..fcbf255 100644 --- a/timed_decorator/builder.py +++ b/timed_decorator/builder.py @@ -8,7 +8,7 @@ def create_timed_decorator(name: str, - nested: bool = True, + nested: bool = False, collect_gc: bool = True, disable_gc: bool = False, use_seconds: bool = False, @@ -31,7 +31,7 @@ def create_timed_decorator(name: str, name (str): The name of the timed decorator which will be instantiated using the provided arguments. Use this name for retrieving the timed decorator with :class:`timed_decorator.builder.get_timed_decorator`. nested (bool): If `True`, uses the :class:`timed_decorator.nested_timed.nested_timed` as decorator, otherwise - uses :class:`timed_decorator.simple_timed.timed`. + uses :class:`timed_decorator.simple_timed.timed`. Default: `False`. See Also: :class:`timed_decorator.simple_timed.timed` for the remaining parameters' documentation. From 3a52dee429f23eaba750769c1a133771d5743279 Mon Sep 17 00:00:00 2001 From: ancestor-mithril Date: Wed, 1 May 2024 11:45:23 +0300 Subject: [PATCH 4/4] Added tests for create and get timed decorator --- tests/test_usage.py | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/tests/test_usage.py b/tests/test_usage.py index 9a21e07..58a5f05 100644 --- a/tests/test_usage.py +++ b/tests/test_usage.py @@ -5,6 +5,7 @@ from time import sleep from tests.functions import fibonacci, recursive_fibonacci +from timed_decorator.builder import create_timed_decorator, get_timed_decorator from timed_decorator.nested_timed import nested_timed from timed_decorator.simple_timed import timed from timed_decorator.utils import build_decorated_fn @@ -141,6 +142,21 @@ def fn(x): self.assertIsInstance(elapsed, int) self.assertGreater(elapsed / 1e+9, seconds) + def test_create_timed_decorator(self): + create_timed_decorator('same name') + self.assertRaises(KeyError, create_timed_decorator, 'same name') + create_timed_decorator('other name') + + get_timed_decorator('same name')(fibonacci)(10000) + get_timed_decorator('other name')(fibonacci)(10000) + fn = get_timed_decorator('no name')(fibonacci) # Does not raise error if not called + self.assertRaises(KeyError, fn, 10000) + + # Defer instantiation + fn = get_timed_decorator('lazy name')(fibonacci) + create_timed_decorator('lazy name') + fn(10000) + if __name__ == '__main__': unittest.main()