Skip to content

Instantly share code, notes, and snippets.

@bradmontgomery
Last active December 1, 2023 21:01
Show Gist options
  • Save bradmontgomery/bd6288f09a24c06746bbe54afe4b8a82 to your computer and use it in GitHub Desktop.
Save bradmontgomery/bd6288f09a24c06746bbe54afe4b8a82 to your computer and use it in GitHub Desktop.
A python decorator that logs execution time.
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()
@saif-mahmud
Copy link

saif-mahmud commented Feb 8, 2021

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment