跟踪函数调用记录时间答案

【问题标题】：Tracking function calls for logging time跟踪函数调用记录时间
【发布时间】：2019-06-05 22:43:59
【问题描述】：

不确定这在 Python 中是否可行，但我正在尝试分析一个大型函数并指出它的哪些部分正在处理/I/O 很慢。我试图写几个装饰器函数；一个顶级函数来包装被分析的函数。如果超过顶级装饰器的阈值，一些嵌套函数的装饰器会报告它们的时间。不过，我不确定如何在装饰器之间共享此上下文。

顶级装饰器

def time_stack(name, threshold=60000):
    def wrapper(f):
        def wrapped(*args, **kwargs):
            start = time_millis()
            f(*args, **kwargs)
            end = time_millis()
            if end - start > threshold:
                # Log out frame timings here
        return wrapped
    return wrapper

对于嵌套函数

def time_frame(name):
    def wrapper(f):
        def wrapped(*args, **kwargs):
            start = time_millis()
            f(*args, **kwargs)
            end = time_millis()
            t = end - start
            # Somehow remember this value for the outer time_stack to use if needed
        return wrapped
    return wrapper

例子

@time_frame(name="do_some_io")
def do_some_io(string):
    # do some io

@time_frame(name="do_a_transform")
def do_a_transform(result):
    # do some transforming

@time_frame(name="do_some_caching")
def do_some_caching(stuff):
    # do some caching

@time_stack(name="search", threshold=100000):
def search(string):
    result = do_some_io(string)
    transformed = do_a_transform(result)
    return do_some_caching(transformed)

这里，如果搜索的执行时间超过100000ms，它会打印出类似的东西

search took 123456ms
    do_some_io: 23000ms
    do_a_transform: 13678ms
    do_some_caching: 86778ms

我虽然关于通过 kwargs 向下传递一个对象以跟踪时间，但是调用堆栈中的所有函数都必须在其签名中包含 **kwargs，如果有一种方法可以实现这一点而不必这样做会更好。

【问题讨论】：

你不使用line_profiler的原因是什么？
您是否尝试过使用cProfile？
可以在软件运行时使用其中任何一个，并在野外进行实时函数调用吗？还是您必须向它们提供显式参数并手动运行它们？

标签： python decorator python-decorators

【解决方案1】：

您可以定义一个全局堆栈来保存每个 time_frame 的数据。它将在调用函数之前在 time_stack 上设置，并在函数结束时重置。如果时间已超过阈值，您可以使用其数据。但是，应该只有一个 time_stack。对于多个 time_stack 函数，应该有一个包含堆栈的堆栈。这个想法的草图是这样的：

PROFILE_STACK = []
STACK_IS_SET = False
def time_stack(name, threshold=60000):
    def wrapper(f):
        def wrapped(*args, **kwargs):
            PROFILE_IS_SET = True
            start = time_millis()
            f(*args, **kwargs)
            end = time_millis()
            if end - start > threshold:
                # use PROFILE_STACK
            PROFILE_STACK.clear()
            STACK_IS_SET = False
        return wrapped
    return wrapper

和

def time_frame(name):
    def wrapper(f):
        def wrapped(*args, **kwargs):
            start = time_millis()
            f(*args, **kwargs)
            end = time_millis()
            t = end - start
            if STACK_IS_SET:
                PROFILE_STACK.append("SOMETHING")
            # Somehow remember this value for the outer time_stack to use if needed
        return wrapped
    return wrapper

【讨论】：