timeit 及其 default_timer 完全不同意

timeit and its default_timer completely disagree

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

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   

很明显 f1f2 快很多,对吗?

但后来我也用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()

正如 Martijn 评论的那样,区别在于 Python 的垃圾收集,timeit.timeit 在其 运行 期间禁用。 zip creates 10 million iterator objects,它给出的 1000 万个可迭代对象中的每一个。

所以,garbage-collecting 1000 万个对象需要很多时间,对吧?谜团解开了!

嗯...不。事实并非如此,而且比这更有趣。在现实生活中,要让这样的代码更快,需要吸取教训。

Python丢弃不再需要的对象的主要方式是引用计数。此处禁用的垃圾收集器用于引用 cycles,引用计数不会捕获。而且这里没有任何循环,所以它全部被引用计数丢弃,垃圾收集器实际上并没有收集任何垃圾。

让我们来看看一些事情。首先,让我们自己禁用垃圾收集器来重现更快的时间。

通用设置代码(所有进一步的代码块应该在 运行 之后直接在一个新的 运行 中,不要合并它们):

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)

我运行它三次,用了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 代中。如果它们在进一步的集合中存活 运行在那里,他们留在第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 代,还有多达 18 个已经在生成中2).我们也可以注册一个回调来更精确地计数:

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()

在我们这里的例子中,垃圾收集的成本并不高m 来自其他一些不相关的代码。这是直接由 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() 结束以在我完成后重新打开垃圾收集。那时,由于引用计数,所有这些临时对象都已被丢弃。所以我所做的就是避免大量无意义的垃圾收集检查。我发现这是一个宝贵的教训,如果我知道我只是临时创建了很多对象,我将来可能真的会这样做。

最后,我强烈推荐阅读 Python 的开发者指南中的 gc module documentation and the Design of CPython’s Garbage Collector。大部分内容通俗易懂,我觉得很有趣,很有启发性。