使用装饰器记录执行时间

Question

试了一段时间不成功，求助于这个神奇的网站。现在解决我的问题：我想创建一个装饰器，它将函数的执行时间（在函数执行期间）写入一个日志文件如：

@log_time("log.txt", 35)
def some_function(...):
    ...
    return result

和

from functools import wraps

def log_time(path_to_logfile, interval):
    ...

所以 log.txt 看起来像

Time elapsed: 0h 0m 35s
Time elapsed: 0h 1m 10s
Time elapsed: 0h 1m 45s

有什么想法吗？

Answer 1

快速组合，但在一些功能上使用@timeit 进行了测试。

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

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

编辑：我发现 Python 带有一个非常好的日志模块；为什么 re-invent 轮子？

Answer 2

我将向您简要介绍要完成此操作必须执行的操作。下面是一个接受两个参数并执行函数的装饰器。缺少的功能以注释形式呈现，将它们添加到：

def log_time(path_to_logfile, interval):
    def log(func):
        # 'wrap' this puppy up if needed 
        def wrapped(*args, **kwargs):
            # start timing
            func(*args, **kwargs)
            # stop timing
            with open(path_to_logfile, 'a') as f:
                pass # functionality
        return wrapped
    return log

您现在可以修饰函数，输出将写入 path_to_logfile。因此，例如，在此处装饰 foo：

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

foo(1, 2)

将获取 foo 并执行它。您需要适当 time 它并将内容写入您的文件。您应该更多地尝试装饰器并阅读它们，一篇关于 Decorators exist at the Python Wiki 的好文章。

Answer 3

好吧，我终于想通了线程。感谢所有的建议！

import codecs, threading, time
from functools import wraps

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

    def log_time_decorator(func):
        @wraps(func)
        def wrapper(*args, **kwargs):
            t = threading.Thread(target=func, args=args, kwargs=kwargs)
            log_entries = 0
            with 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 += 1
        return wrapper
    return log_time_decorator

一个缺点可能是您无法轻松检索函数的 return 值（至少我还没有弄清楚）。

EDIT1：删除了一个不必要的变量并添加了一个很好的日志写入格式（参见this）

EDIT2：即使其他用户拒绝了他的编辑，我还是想包含来自 Piotr Dabkowski 的一个版本，因为它适用于 return-value:

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

    def log_time_decorator(func):
        @wraps(func)
        def wrapper(*args, **kwargs):
            RESULT = [None]
            def temp():
                RESULT[0] = func(*args, **kwargs)
            t = threading.Thread(target=temp)
            log_entries = 0
            with 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 += 1
            return RESULT[0]
        return wrapper
    return log_time_decorator

使用装饰器记录执行时间

Logging execution time with decorators

python

logging

python-2.7

functools

python-decorators