有没有办法对多次执行的代码块进行计时？

Posted 2023-02-23

【中文标题】有没有办法对多次执行的代码块进行计时？

【英文标题】：Is there a way to time a block of code that is executed many times?

【发布时间】：2021-05-07 08:15:23

【问题描述】：

给定一个类似的函数：

do_something_big():
  do_1()
  do_2()
  do_3()

很容易获得运行do_something_big() 或do_1() 的单个实例所需的时间。但假设我有：

for _ in range(100000):
  do_something_big()

有没有一种简单的方法可以计算 100,000 do_1 花了多长时间？做到这一点并不难——您只需为每个时间计时并更新一些全局状态以跟踪聚合时间。但是是否已经构建了一个实用程序来为我抽象这个？

【问题讨论】：

您可以使用timeit 进行迭代计时

是的，我看过了 - 问题是它适用于传入的表达式；在这种情况下这行不通（据我所知）你能举一个例子说明你在do_1() 周围添加的内容，如果可行的话？

您需要通过运行 do_something_big 来为 do_1,do_2 的 100,000 次试验争取时间？

是的，如上例所示。

【参考方案1】：

我建议使用例如个人资料。这个包将对代码中的每个函数进行计时，并以良好的格式输出：

import cProfile

pr = cProfile.Profile()
pr.enable()

run_your_program_here()

pr.disable()
pr.print_stats(sort='tottime')

最后一行中的 sort 参数将根据您给定的选项对输出进行排序。你可以阅读更多关于它here:

ncalls – 函数/方法被调用了多少次（如果相同的函数/方法被递归调用，那么 ncalls 有两个值，例如 120/20，其中第一个是真实调用次数，第二是直接调用次数）

tottime – 以秒为单位的总时间，不包括其他函数/方法的时间

percall – 执行函数的平均时间（每次调用）

cumtime – 以秒为单位的总时间包括它调用的其他函数的时间

percall – 与之前的 percall 类似，但是这个包括网络延迟、线程休眠等……

在您的情况下，我会使用“tottime”并查看 do_1 花费了多少时间。

【讨论】：

这是一个合理的做法；我试过了，但对另一个分析库 pyinstrument 有更好的体验。无论哪种方式，这似乎都是最好的选择。

感谢 Rollie，很高兴为您解决了问题！

@Rollie 也许您可以使用pyinstrument 为后代发布答案？

【参考方案2】：

这是一个 decorator 作为您正在寻找的实用程序。灵感来自here 和here。

我们创建了一个装饰器@timeit。我们使用这个带有可选n 参数的装饰器来注释我们的方法。当达到n 调用时，打印此方法的时间度量，否则在每次调用时打印。

from functools import wraps
from time import time
from collections import defaultdict
timedata = defaultdict(lambda : (0, 0.0))
    
def timeit(*decArgs, **decKw):
    def _timeit(func):
        @wraps(func)
        def timed(*args, **kw):
            name = func.__name__.upper()
            n = decKw.get('n', 1)
            if timedata[name][0] >= n:
                return func(*args, **kw)

            ts = time()
            result = func(*args, **kw)
            te = time()
            duration = int((te - ts) * 1000)
            
            cnt, ave = timedata[name]
            cnt += 1
            timedata[name] = (cnt, ((cnt-1) * ave + duration) / cnt)
            if n == cnt:
                print(f'name:30s: [n:6dx] -> ave*cnt:7.3fms (ave:6.3fms ave)')
                timedata[name] = (0, 0.0)
            return result
        return timed
    return _timeit

用法：

from random import random

@timeit(n=100)
def do_1():
    sleep(random()/1000)

@timeit(n=3)
def do_something_big():
    for _ in range(200):
        do_1()

for _ in range(5):
    do_something_big()

输出：

DO_1                          : [   100x] ->  19.192ms ( 0.192ms ave)
DO_1                          : [   100x] ->  23.232ms ( 0.232ms ave)
DO_1                          : [   100x] ->  24.242ms ( 0.242ms ave)
DO_1                          : [   100x] ->  18.182ms ( 0.182ms ave)
DO_1                          : [   100x] ->  14.141ms ( 0.141ms ave)
DO_1                          : [   100x] ->  23.232ms ( 0.232ms ave)
DO_SOMETHING_BIG              : [     3x] -> 393.000ms (131.000ms ave)
DO_1                          : [   100x] ->  27.273ms ( 0.273ms ave)
DO_1                          : [   100x] ->  22.222ms ( 0.222ms ave)
DO_1                          : [   100x] ->  21.212ms ( 0.212ms ave)
DO_1                          : [   100x] ->  24.242ms ( 0.242ms ave)

【讨论】：

问题需要通过运行 do_something_big 为 do_1() 找到时间，这如何计算 do_1 时间？

@GirishSrivatsa 我已经更新了示例代码，希望能解决您的问题。对于比这更复杂的事情，@eligolf 的cProfile 回答似乎是您最好的选择

是的，这就是我想要的，以已经构建的形式。如果我手动推出解决方案，这就是我希望实现它的方式，但我认为正确的方法毕竟是分析。

【参考方案3】：

这是我在互联网上找到的https://realpython.com/python-timer/： 您将为 Python 计时器添加可选名称。您可以将该名称用于两种不同的目的：

稍后在您的代码中查找经过的时间 累加同名定时器 要为 Python 计时器添加名称，您需要对 timer.py 进行另外两项更改。首先，Timer 应该接受名称作为参数。其次，当计时器停止时，应将经过的时间添加到 .timers 中：

类计时器： timers = dict()

def __init__(
    self,
    name=None,
    text="Elapsed time: :0.4f seconds",
    logger=print,
):
    self._start_time = None
    self.name = name
    self.text = text
    self.logger = logger

    # Add new named timers to dictionary of timers
    if name:
        self.timers.setdefault(name, 0)

# Other methods are unchanged

def stop(self):
    """Stop the timer, and report the elapsed time"""
    if self._start_time is None:
        raise TimerError(f"Timer is not running. Use .start() to start it")

    elapsed_time = time.perf_counter() - self._start_time
    self._start_time = None

    if self.logger:
        self.logger(self.text.format(elapsed_time))
    if self.name:
        self.timers[self.name] += elapsed_time

    return elapsed_time

请注意，在将新的 Python 计时器添加到 .timers 时，您会使用 .setdefault()。这是一个很棒的功能，仅当名称尚未在字典中定义时才设置值。如果 name 已在 .timers 中使用，则该值保持不变。这允许您累积多个计时器：

>>> from timer import Timer
>>> t = Timer("accumulate")
>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 3.7036 seconds
3.703554293999332

>>> t.start()

>>> t.stop()  # A few seconds later
Elapsed time: 2.3449 seconds
2.3448921170001995

>>> Timer.timers
'accumulate': 6.0484464109995315