为啥 python profiler 给出了矛盾的结果？

Posted 2023-03-06

【中文标题】为啥 python profiler 给出了矛盾的结果？

【英文标题】：Why python profiler gives contradicting results?为什么 python profiler 给出了矛盾的结果？

【发布时间】：2015-07-19 22:44:03

【问题描述】：

玩一下python profiler，看下面的代码：

>>> def testa():
...     a = []
...     pr = cProfile.Profile()
...     pr.enable()
...     for i in range(100000):
...             a.append(1)
...     pr.disable()
...     pr.print_stats()

>>> def testb():
...     a = []
...     pr = cProfile.Profile()
...     pr.enable()
...     for i in range(100000):
...             a = a + [1]
...     pr.disable()
...     pr.print_stats()

基本上我想看看append 方法与自连接列表之间的结果，我认为自连接会更昂贵，而当我调用testb 时，它实际上需要更长的时间才能完成。

但是分析器的结果是错误的？

>>> testa()
         100002 function calls in 0.006 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   100000    0.005    0.000    0.005    0.000 method 'append' of 'list' objects
        1    0.000    0.000    0.000    0.000 method 'disable' of '_lsprof.Profiler' objects
        1    0.001    0.001    0.001    0.001 range


>>> testb()
         2 function calls in 0.001 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 method 'disable' of '_lsprof.Profiler' objects
        1    0.001    0.001    0.001    0.001 range

【问题讨论】：

使用timeit，你会看到很大的不同，a=[];for i in range(100000);a = a + [1] -> 22s，a=[];for i in range(100000);a.append(1) -> 7.84ms。

【参考方案1】：

您错误地使用了探查器。它不会报告您打开它和关闭它之间经过的时间；它正在收集有关在您打开它和关闭它时调用的函数的统计信息。 testb 中昂贵的大循环没有计时，因为没有发生函数调用。

如果您只是想计时，cProfile 不是可以使用的工具。我通常会推荐timeit，但由于testb 花费的时间非常长，time.time() 也比较合适：

def testb():
    start = time.time()
    a = []
    for i in range(100000):
        a = a + [1]
    print time.time() - start

【参考方案2】：

Python 每次都必须查找列表的“追加”方法的含义。语言非常动态，方法可能随时改变。为了改善这一点，查找 append 方法一次，然后定期追加：

>>> def testc():
...     a = []
...     pr = cProfile.Profile()
...     pr.enable()
...     list_append = a.append
...     for i in range(100000):
...             list_append(1)
...     pr.disable()
...     pr.print_stats()

【讨论】：

这是有用的信息，但为什么分析器说时间更少，但实际上完成 testb 需要大约 5 秒？

@JamesLin：它会发生一次还是每次？我想不出为什么会发生这种情况。

是的，它每次都会发生。