-
-
Save bradmontgomery/bd6288f09a24c06746bbe54afe4b8a82 to your computer and use it in GitHub Desktop.
Copyright 2020 Brad Montgomery | |
Permission is hereby granted, free of charge, to any person obtaining a copy of this software | |
and associated documentation files (the "Software"), to deal in the Software without restriction, | |
including without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense, | |
and/or sell copies of the Software, and to permit persons to whom the Software is furnished to do so, | |
subject to the following conditions: | |
The above copyright notice and this permission notice shall be included in all copies or substantial | |
portions of the Software. | |
THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT | |
LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN | |
NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, | |
WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE | |
SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. |
""" | |
A simple execution time logger implemented as a python decorator. | |
Available under the terms of the MIT license. | |
""" | |
import logging | |
import time | |
from functools import wraps | |
logger = logging.getLogger(__name__) | |
# Misc logger setup so a debug log statement gets printed on stdout. | |
logger.setLevel("DEBUG") | |
handler = logging.StreamHandler() | |
log_format = "%(asctime)s %(levelname)s -- %(message)s" | |
formatter = logging.Formatter(log_format) | |
handler.setFormatter(formatter) | |
logger.addHandler(handler) | |
def timed(func): | |
"""This decorator prints the execution time for the decorated function.""" | |
@wraps(func) | |
def wrapper(*args, **kwargs): | |
start = time.time() | |
result = func(*args, **kwargs) | |
end = time.time() | |
logger.debug("{} ran in {}s".format(func.__name__, round(end - start, 2))) | |
return result | |
return wrapper | |
@timed | |
def slow_function(): | |
"""This is a slow-running function used as an example.""" | |
print("running a slow function...", end="") | |
time.sleep(3.2) | |
print("done") | |
if __name__ == "__main__": | |
slow_function() |
@ayvazc: you probably need to set your loggers level to debug first, otherwise the actuall log record will be discarded. One way to do so: add after line 4:
logger.setLevel('DEBUG')
Though in your full program, that should probably be done elsewhere.
Missing import time
😅 things that happen when you copy/paste from other sources... Updated this gist to include a working example.
What's the license for this? I'm tired writing these things each time from scratch.
@matanster
What's the license for this? I'm tired writing these things each time from scratch.
I just added a license; it's MIT, feel free to use this in your projects.
Here's my own, which I ended up using again. It's not a decorator though, but it caters for more scenarios. I added fn.__name__
from you, to my old code. Thanks again for sharing.
def timed(fn, *args, human_fn_description=None, warning_threshold=None, always=False, **kwargs):
""" executes a function while timing its elapsed time, and logging it according to the supplied parameters """
if not human_fn_description:
human_fn_description = fn.__name__
now = time.time()
result = fn(*args, **kwargs)
duration = time.time() - now
if warning_threshold is None:
if always:
logging.info(f'{human_fn_description} took {duration:.3f} seconds')
elif duration > warning_threshold:
logging.warning(f'{human_fn_description} took {duration:.3f} seconds')
return result, duration
I have written a modified one: https://gist.github.com/saif-mahmud/793735279ebd367ea1855470c5bdd33f
Example Usage:
def func(a, b):
time.sleep(1.5)
return a + b, a - b
t_log = TimeLogger()
for i in range(1, 10):
res = t_log.timed(func, i, i + 5, description='Operation on Integers', verbose=True)
# print(res)
t_log.summary()
Output:
2021-02-08 13:24:59.953 INFO -- [Operation on Integers] Elapsed Time : 1.50175 sec
2021-02-08 13:25:01.455 INFO -- [Operation on Integers] Elapsed Time : 1.50173 sec
2021-02-08 13:25:02.957 INFO -- [Operation on Integers] Elapsed Time : 1.50161 sec
2021-02-08 13:25:04.459 INFO -- [Operation on Integers] Elapsed Time : 1.50173 sec
2021-02-08 13:25:05.961 INFO -- [Operation on Integers] Elapsed Time : 1.50175 sec
2021-02-08 13:25:07.462 INFO -- [Operation on Integers] Elapsed Time : 1.50171 sec
2021-02-08 13:25:08.965 INFO -- [Operation on Integers] Elapsed Time : 1.50175 sec
2021-02-08 13:25:10.467 INFO -- [Operation on Integers] Elapsed Time : 1.50174 sec
2021-02-08 13:25:11.969 INFO -- [Operation on Integers] Elapsed Time : 1.5016 sec
[Operation on Integers] Avg. Elapsed Time : 1.50171 sec
hi,
where code logs execution time? when ı run your code there is no execution time in my output.