From d47f5cf99fa98f3aa752ec3dff9906c07610e067 Mon Sep 17 00:00:00 2001 From: wpbonelli Date: Fri, 29 Sep 2023 08:38:13 -0400 Subject: [PATCH 1/3] Revert "Revert "feat(timeit): add function timing decorator (#118)" (#119)" This reverts commit d725ddb13bdfe4cee45865a7412811765714891a. --- docs/index.rst | 1 + docs/md/timeit.md | 17 ++++++++++++++ modflow_devtools/misc.py | 37 ++++++++++++++++++++++++++++++ modflow_devtools/test/test_misc.py | 24 +++++++++++++++++++ 4 files changed, 79 insertions(+) create mode 100644 docs/md/timeit.md diff --git a/docs/index.rst b/docs/index.rst index cbeaa40..393f81b 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -31,6 +31,7 @@ The `modflow-devtools` package provides a set of tools for developing and testin md/download.md md/ostags.md md/zip.md + md/timeit.md .. toctree:: diff --git a/docs/md/timeit.md b/docs/md/timeit.md new file mode 100644 index 0000000..c57ef85 --- /dev/null +++ b/docs/md/timeit.md @@ -0,0 +1,17 @@ +# `timeit` + +There is a `timeit` decorator function available in the `modflow_devtools.misc` module. Applying it to any function causes a (rough) runtime benchmark to be printed to `stdout` afterwards the function returns. For instance: + +```python +@timeit +def sleep1(): + sleep(0.001) + +sleep1() # prints e.g. "sleep1 took 1.26 ms" +``` + +`timeit` can also directly wrap a function: + +```python +timeit(sleep1)() # prints same as above +``` \ No newline at end of file diff --git a/modflow_devtools/misc.py b/modflow_devtools/misc.py index 7dd9210..284a6ed 100644 --- a/modflow_devtools/misc.py +++ b/modflow_devtools/misc.py @@ -1,8 +1,10 @@ import importlib import socket import sys +import time import traceback from contextlib import contextmanager +from functools import wraps from importlib import metadata from os import PathLike, chdir, environ, getcwd from os.path import basename, normpath @@ -442,3 +444,38 @@ def try_metadata() -> bool: _has_pkg_cache[pkg] = found return _has_pkg_cache[pkg] + + +def timeit(f): + """ + Decorator for estimating runtime of any function. + Prints estimated time to stdout, in milliseconds. + + Parameters + ---------- + f : function + Function to time. + + Notes + ----- + Adapted from https://stackoverflow.com/a/27737385/6514033. + + Returns + ------- + function + The decorated function. + """ + + @wraps(f) + def timed(*args, **kw): + ts = time.time() + res = f(*args, **kw) + te = time.time() + if "log_time" in kw: + name = kw.get("log_name", f.__name__.upper()) + kw["log_time"][name] = int((te - ts) * 1000) + else: + print(f"{f.__name__} took {(te - ts) * 1000:.2f} ms") + return res + + return timed diff --git a/modflow_devtools/test/test_misc.py b/modflow_devtools/test/test_misc.py index 79ea786..b8ebd40 100644 --- a/modflow_devtools/test/test_misc.py +++ b/modflow_devtools/test/test_misc.py @@ -1,8 +1,10 @@ import os +import re import shutil from os import environ from pathlib import Path from pprint import pprint +from time import sleep from typing import List import pytest @@ -15,6 +17,7 @@ has_pkg, set_dir, set_env, + timeit, ) @@ -283,3 +286,24 @@ def test_has_pkg(virtualenv): ).strip() == exp ) + + +def test_timeit1(capfd): + def sleep1(): + sleep(0.001) + + timeit(sleep1)() + cap = capfd.readouterr() + print(cap.out) + assert re.match(r"sleep1 took \d+\.\d+ ms", cap.out) + + +def test_timeit2(capfd): + @timeit + def sleep1dec(): + sleep(0.001) + + sleep1dec() + cap = capfd.readouterr() + print(cap.out) + assert re.match(r"sleep1dec took \d+\.\d+ ms", cap.out) From c495cd80c9434ace8b8a20821a595a2f61ba14b8 Mon Sep 17 00:00:00 2001 From: w-bonelli Date: Fri, 29 Sep 2023 14:13:11 -0400 Subject: [PATCH 2/3] rename timeit -> timed, use builtin timeit internally --- modflow_devtools/misc.py | 24 +++++++++++++++--------- modflow_devtools/test/test_misc.py | 14 ++++++-------- 2 files changed, 21 insertions(+), 17 deletions(-) diff --git a/modflow_devtools/misc.py b/modflow_devtools/misc.py index 284a6ed..9646aee 100644 --- a/modflow_devtools/misc.py +++ b/modflow_devtools/misc.py @@ -1,7 +1,6 @@ import importlib import socket import sys -import time import traceback from contextlib import contextmanager from functools import wraps @@ -11,6 +10,7 @@ from pathlib import Path from shutil import which from subprocess import PIPE, Popen +from timeit import timeit from typing import List, Optional, Tuple from urllib import request @@ -446,7 +446,7 @@ def try_metadata() -> bool: return _has_pkg_cache[pkg] -def timeit(f): +def timed(f): """ Decorator for estimating runtime of any function. Prints estimated time to stdout, in milliseconds. @@ -459,6 +459,7 @@ def timeit(f): Notes ----- Adapted from https://stackoverflow.com/a/27737385/6514033. + Uses the built-in timeit module internally. Returns ------- @@ -467,15 +468,20 @@ def timeit(f): """ @wraps(f) - def timed(*args, **kw): - ts = time.time() - res = f(*args, **kw) - te = time.time() + def _timed(*args, **kw): + res = None + + def call(): + nonlocal res + res = f(*args, **kw) + + t = timeit(lambda: call(), number=1) if "log_time" in kw: name = kw.get("log_name", f.__name__.upper()) - kw["log_time"][name] = int((te - ts) * 1000) + kw["log_time"][name] = int(t * 1000) else: - print(f"{f.__name__} took {(te - ts) * 1000:.2f} ms") + print(f"{f.__name__} took {t * 1000:.2f} ms") + return res - return timed + return _timed diff --git a/modflow_devtools/test/test_misc.py b/modflow_devtools/test/test_misc.py index b8ebd40..ff4f980 100644 --- a/modflow_devtools/test/test_misc.py +++ b/modflow_devtools/test/test_misc.py @@ -3,7 +3,6 @@ import shutil from os import environ from pathlib import Path -from pprint import pprint from time import sleep from typing import List @@ -14,10 +13,9 @@ get_namefile_paths, get_packages, has_package, - has_pkg, set_dir, set_env, - timeit, + timed, ) @@ -28,7 +26,7 @@ def test_set_dir(tmp_path): assert Path(os.getcwd()) != tmp_path -def test_set_env(tmp_path): +def test_set_env(): # test adding a variable key = "TEST_ENV" val = "test" @@ -288,18 +286,18 @@ def test_has_pkg(virtualenv): ) -def test_timeit1(capfd): +def test_timed1(capfd): def sleep1(): sleep(0.001) - timeit(sleep1)() + timed(sleep1)() cap = capfd.readouterr() print(cap.out) assert re.match(r"sleep1 took \d+\.\d+ ms", cap.out) -def test_timeit2(capfd): - @timeit +def test_timed2(capfd): + @timed def sleep1dec(): sleep(0.001) From dc9147920a8039d6d22ab4c0e1dcb27754680d87 Mon Sep 17 00:00:00 2001 From: w-bonelli Date: Fri, 29 Sep 2023 16:59:53 -0400 Subject: [PATCH 3/3] update docs --- docs/index.rst | 2 +- docs/md/timed.md | 21 +++++++++++++++++++++ docs/md/timeit.md | 17 ----------------- 3 files changed, 22 insertions(+), 18 deletions(-) create mode 100644 docs/md/timed.md delete mode 100644 docs/md/timeit.md diff --git a/docs/index.rst b/docs/index.rst index 393f81b..e71195d 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -31,7 +31,7 @@ The `modflow-devtools` package provides a set of tools for developing and testin md/download.md md/ostags.md md/zip.md - md/timeit.md + md/timed.md .. toctree:: diff --git a/docs/md/timed.md b/docs/md/timed.md new file mode 100644 index 0000000..d4de7ab --- /dev/null +++ b/docs/md/timed.md @@ -0,0 +1,21 @@ +# `timed` + +There is a `@timed` decorator function available in the `modflow_devtools.misc` module. Applying it to any function prints a (rough) benchmark to `stdout` when the function returns. For instance: + +```python +from modflow_devtools.misc import timed + +@timed +def sleep1(): + sleep(0.001) + +sleep1() # prints e.g. "sleep1 took 1.26 ms" +``` + +It can also wrap a function directly: + +```python +timed(sleep1)() +``` + +The [`timeit`](https://docs.python.org/3/library/timeit.html) built-in module is used internally, however the timed function is only called once, where by default, `timeit` averages multiple runs. \ No newline at end of file diff --git a/docs/md/timeit.md b/docs/md/timeit.md deleted file mode 100644 index c57ef85..0000000 --- a/docs/md/timeit.md +++ /dev/null @@ -1,17 +0,0 @@ -# `timeit` - -There is a `timeit` decorator function available in the `modflow_devtools.misc` module. Applying it to any function causes a (rough) runtime benchmark to be printed to `stdout` afterwards the function returns. For instance: - -```python -@timeit -def sleep1(): - sleep(0.001) - -sleep1() # prints e.g. "sleep1 took 1.26 ms" -``` - -`timeit` can also directly wrap a function: - -```python -timeit(sleep1)() # prints same as above -``` \ No newline at end of file