python - timeit 和它的 default_timer 完全不同意

Question

我对这两个函数进行了基准测试(它们将配对解压缩回源列表，来自 here ):

n = 10**7
a = list(range(n))
b = list(range(n))
pairs = list(zip(a, b))

def f1(a, b, pairs):
    a[:], b[:] = zip(*pairs)

def f2(a, b, pairs):
    for i, (a[i], b[i]) in enumerate(pairs):
        pass

结果与 timeit.timeit (五轮，数字是秒):

f1 1.06   f2 1.57   
f1 0.96   f2 1.69   
f1 1.00   f2 1.85   
f1 1.11   f2 1.64   
f1 0.95   f2 1.63   

这么清楚f1比f2快很多， 对？
但后来我也测量了 timeit.default_timer并得到了完全不同的图片:

f1 7.28   f2 1.92   
f1 5.34   f2 1.66   
f1 6.46   f2 1.70   
f1 6.82   f2 1.59   
f1 5.88   f2 1.63   

这么清楚f2快了很多，对吧？
叹。为什么计时完全不同，我应该相信哪种计时方法？
完整的基准代码:

from timeit import timeit, default_timer

n = 10**7
a = list(range(n))
b = list(range(n))
pairs = list(zip(a, b))

def f1(a, b, pairs):
    a[:], b[:] = zip(*pairs)

def f2(a, b, pairs):
    for i, (a[i], b[i]) in enumerate(pairs):
        pass

print('timeit')
for _ in range(5):
    for f in f1, f2:
        t = timeit(lambda: f(a, b, pairs), number=1)
        print(f.__name__, '%.2f' % t, end='   ')
    print()

print('default_timer')
for _ in range(5):
    for f in f1, f2:
        t0 = default_timer()
        f(a, b, pairs)
        t = default_timer() - t0
        print(f.__name__, '%.2f' % t, end='   ')
    print()

Answer 1

正如 Martijn 所评论的，区别在于 Python 的垃圾收集，即 timeit.timeit在其运行期间禁用。和 zip creates 10 million iterator objects ，给定的 1000 万个可迭代对象中的每一个对应一个。
所以，垃圾收集 1000 万个对象需要很多时间，对吧？谜团已揭开!
嗯……不。这并不是真正发生的事情，而且比这更有趣。在现实生活中，有一个教训可以让这样的代码更快。
Python 丢弃不再需要的对象的主要方法是引用计数。垃圾收集器在这里被禁用，用于引用循环，引用计数不会捕获。并且这里没有任何循环，所以它都被引用计数丢弃了，垃圾收集器实际上并不收集任何垃圾。
让我们来看看一些事情。首先，让我们通过自己禁用垃圾收集器来重现更快的时间。
通用设置代码(所有其他代码块应在此之后直接在新运行中运行，不要组合它们):

import gc
from timeit import default_timer as timer

n = 10**7
a = list(range(n))
b = list(range(n))
pairs = list(zip(a, b))

启用垃圾收集的计时(默认):

t0 = timer()
a[:], b[:] = zip(*pairs)
t1 = timer()
print(t1 - t0)

我跑了 3 次，分别用了 7.09、7.03 和 7.09 秒。
禁用垃圾收集的时间:

t0 = timer()
gc.disable()
a[:], b[:] = zip(*pairs)
gc.enable()
t1 = timer()
print(t1 - t0)

耗时 0.96、1.02 和 0.99 秒。
所以现在我们知道确实是垃圾收集以某种方式占用了大部分时间 ，即使它没有收集任何东西。
这里有一些有趣的事情:已经只是 zip 的创建。迭代器大部分时间负责:

t0 = timer()
z = zip(*pairs)
t1 = timer()
print(t1 - t0)

这花了 6.52、6.51 和 6.50 秒。
请注意，我保留了 zip变量中的迭代器，因此甚至没有任何东西可以丢弃，无论是通过引用计数还是通过垃圾收集!
什么？!那么时间都去哪儿了？
嗯...正如我所说，没有引用循环，所以垃圾收集器实际上不会收集任何垃圾。但是垃圾收集器不知道!为了弄清楚这一点，它需要检查!
由于迭代器可能成为引用循环的一部分，因此它们被注册以进行垃圾收集跟踪。让我们看看有多少对象因为 zip 而被跟踪创建(在通用设置代码之后执行此操作):

gc.collect()
tracked_before = len(gc.get_objects())
z = zip(*pairs)
print(len(gc.get_objects()) - tracked_before)

输出:10000003跟踪的新对象。我相信那是 zip对象本身，它的内部元组来保存迭代器，它的内部 result holder元组和 1000 万个迭代器。
好的，垃圾收集器跟踪所有这些对象。但是，这是什么意思？好吧，每隔一段时间，在创建一定数量的新对象之后，收集器就会检查跟踪的对象，看看是否有一些是垃圾并且可以丢弃。收集器保留三个“世代”的跟踪对象。新对象进入第 0 代。如果它们在那里的集合运行中幸存下来，它们将被移到第 1 代。如果它们在那里的一个集合中幸存下来，它们将被移到第 2 代。如果它们在那里的进一步收集运行中幸存下来，它们将留在第 1 代2.让我们检查一下前后几代:

gc.collect()
print('collections:', [stats['collections'] for stats in gc.get_stats()])
print('objects:', [len(gc.get_objects(i)) for i in range(3)])
z = zip(*pairs)
print('collections:', [stats['collections'] for stats in gc.get_stats()])
print('objects:', [len(gc.get_objects(i)) for i in range(3)])

输出(每行显示三代的值):

collections: [13111, 1191, 2]
objects: [17, 0, 13540]
collections: [26171, 2378, 20]
objects: [317, 2103, 10011140]

10011140 显示 1000 万个迭代器中的大多数不仅注册用于跟踪，而且已经在第 2 代中。因此它们至少是两次垃圾收集运行的一部分。第 2 代收集的数量从 2 次增加到 20 次，因此我们的数百万个迭代器参与了多达 20 次垃圾收集运行(2 次进入第 2 代，而在第 2 代中又增加了 18 次)。我们还可以注册一个回调来更精确地计数:

checks = 0
def count(phase, info):
    if phase == 'start':
        global checks
        checks += len(gc.get_objects(info['generation']))

gc.callbacks.append(count)
z = zip(*pairs)
gc.callbacks.remove(count)
print(checks)

这告诉我总共有 63,891,314 次检查(即，平均而言，每个迭代器是超过 6 次垃圾收集运行的一部分)。这是很多工作。而这一切只是为了创建 zip迭代器，甚至在使用它之前。
同时，循环

for i, (a[i], b[i]) in enumerate(pairs):
    pass

几乎不创建任何新对象。让我们检查跟踪多少 enumerate原因:

gc.collect()
tracked_before = len(gc.get_objects())
e = enumerate(pairs)
print(len(gc.get_objects()) - tracked_before)

输出:3跟踪的新对象( enumerate 迭代器对象本身，它为迭代 pairs 而创建的单个迭代器，以及它将使用的结果元组(代码 here ))。
我会说这回答了“为什么时间完全不同？”的问题。 zip解决方案创建了数百万个经过多次垃圾收集运行的对象，而循环解决方案则没有。因此禁用垃圾收集器有助于 zip解决方案非常好，而循环解决方案并不关心。
现在关于第二个问题:“我应该相信哪种计时方法？”。这是什么 the documentation不得不说(强调我的):

By default, timeit() temporarily turns off garbage collection during the timing. The advantage of this approach is that it makes independent timings more comparable. The disadvantage is that GC may be an important component of the performance of the function being measured. If so, GC can be re-enabled as the first statement in the setup string. For example:

timeit.Timer('for i in range(10): oct(i)', 'gc.enable()').timeit()

在我们这里的例子中，垃圾收集的成本并不是来自其他一些不相关的代码。它是由 zip 直接引起的称呼。当你运行它时，你在现实中确实付出了这个代价。所以在这种情况下，我确实认为它是“被测量功能性能的重要组成部分”。直接回答问题:这里我相信default_timer方法，而不是 timeit方法。或者换一种说法:这里是 timeit方法应该与文档中建议的启用垃圾收集一起使用。
或者……或者，我们实际上可以禁用垃圾收集 作为解决方案的一部分 (不仅用于基准测试):

def f1(a, b, pairs):
    gc.disable()
    a[:], b[:] = zip(*pairs)
    gc.enable()

但这是个好主意吗？这是什么 the gc documentation说:

Since the collector supplements the reference counting already used in Python, you can disable the collector if you are sure your program does not create reference cycles.

听起来这是件好事。但我不确定我不会在程序的其他地方创建引用循环，所以我以 gc.enable() 结束。在我完成后重新打开垃圾收集。此时，由于引用计数，所有这些临时对象都已被丢弃。所以我所做的就是避免大量无意义的垃圾收集检查。我发现这是一个宝贵的教训，如果我知道我只是临时创建了很多对象，我将来可能真的会这样做。
最后，我强烈推荐阅读 gc module documentation和 Design of CPython’s Garbage Collector在 Python 的开发人员指南中。大部分内容很容易理解，我发现它非常有趣和具有启发性。