Logging Execution Time With Decorators

After I tried unsuccessfully for a while, I am seeking help from this miraculous website. Now for my problem: I want to create a decorator that writes the elapsed execution time of

Solution 1:

I'll give you the basic overview about what you must do in order to accomplish this. The following is a decorator that accepts two parameters, and executes the function. The missing funcitonality is presented as comments, add them in:

deflog_time(path_to_logfile, interval):
    deflog(func):
        # 'wrap' this puppy up if needed defwrapped(*args, **kwargs):
            # start timing
            func(*args, **kwargs)
            # stop timingwithopen(path_to_logfile, 'a') as f:
                pass# functionalityreturn wrapped
    return log

You can now decorate functions and the output is going to be written in path_to_logfile. So, for example, decorating foo here:

@log_time('foo.txt', 40)deffoo(i, j):
    print(i, j)

foo(1, 2)

Will take foo and execute it. You need to time it appropriately and write the contents to your file. You should experiment with decorators even more and read up on them, a nice article on Decorators exist at the Python Wiki.

Solution 2:

Okay, I figured something out in the end with threads. Thanks for all the suggestions!

import codecs, threading, time
from functools import wraps

deflog_time(logpath="log.txt", interval=5):

    deflog_time_decorator(func):
        @wraps(func)defwrapper(*args, **kwargs):
            t = threading.Thread(target=func, args=args, kwargs=kwargs)
            log_entries = 0with codecs.open(logpath, "wb", "utf-8") as logfile:
               start_time = time.time()
               t.start()
               while t.is_alive():
                   elapsed_time = (time.time() - start_time)
                   if elapsed_time > interval * log_entries:
                       m, s = divmod(elapsed_time, 60)
                       h, m = divmod(m, 60)
                       logfile.write("Elapsed time: %2dh %2dm %2ds\n" %(h, m, s))
                       log_entries += 1return wrapper
    return log_time_decorator

One disadvantage might be that you cannot easily retrieve the return value of the function (at least I haven't figured it out yet).

EDIT1: Removed an unnecessary variable and added a nice format for logwriting (see this)

EDIT2: Even though other users rejected his edit, I want to include a version from Piotr Dabkowski because it works with a return-value:

deflog_time(logpath="log.txt", interval=5):

    deflog_time_decorator(func):
        @wraps(func)defwrapper(*args, **kwargs):
            RESULT = [None]
            deftemp():
                RESULT[0] = func(*args, **kwargs)
            t = threading.Thread(target=temp)
            log_entries = 0with codecs.open(logpath, "wb", "utf-8") as logfile:
               start_time = time.time()
               t.start()
               while t.is_alive():
                   elapsed_time = (time.time() - start_time)
                   if elapsed_time > interval * log_entries:
                       m, s = divmod(elapsed_time, 60)
                       h, m = divmod(m, 60)
                       logfile.write("Elapsed time: %2dh %2dm %2ds\n" %(h, m, s))
                       log_entries += 1return RESULT[0]
        return wrapper
    return log_time_decorator

Solution 3:

Quickly put together but worked in a test with @timeit on a few functions.

import logging
logging.basicConfig(
    level=logging.DEBUG, 
    filename='myProgramLog.txt', 
    format=' %(asctime)s - %(levelname)s - %(message)s')

import time                                                

def timeit(method):

    def timed(*args, **kw):
        ts = time.time()
        result = method(*args, **kw)
        te = time.time()

        logging.debug('%r (%r, %r) %2.2f sec' % \
              (method.__name__, args, kw, te-ts))
        return result

    return timed

Sources: https://www.andreas-jung.com/contents/a-python-decorator-for-measuring-the-execution-time-of-methods, https://automatetheboringstuff.com/chapter10/

EDIT: I find Python comes with a pretty good logging module; why re-invent the wheel?