cProfile耗时很长

Question

我开始使用 cProfile 来分析我的 Python 脚本的性能。

我发现了一些很奇怪的事情。

当我用 time 来测量我的脚本运行时间时，结果是 4.3 秒。

但当我用 python -m cProfile script.py 来运行时，时间变成了 7.3 秒。

而当我在代码内部运行分析器时：

import profile
profile.run('main()')

结果竟然是 63 秒！！

我能理解在添加性能分析时，可能会多花一点时间，但为什么在外部使用 cProfile 和在代码中使用时，时间差这么大呢？

使用 profile.run 时，为什么会花这么多时间呢？

Answer 1

奇怪的是，你看到的情况其实是正常的。在Python文档的性能分析器介绍部分提到，profile相比于cProfile会给被分析的程序带来“显著的开销”。你看到的差异其实是因为你使用的库不同，而不是你调用它们的方式不同。来看这个脚本：

import profile
import cProfile

def nothing():
    return

def main():
    for i in xrange(1000):
        for j in xrange(1000):
            nothing()

    return

cProfile.run('main()')
profile.run('main()')

使用cProfile的输出显示，主程序运行大约需要0.143秒，而profile的版本则报告需要1.645秒，差不多是前者的11.5倍。

现在我们再把脚本改成这样：

def nothing():
    return

def main():
    for i in xrange(1000):
        for j in xrange(1000):
            nothing()

    return

if __name__ == "__main__":
    main()

然后用性能分析器来调用它：

python -m profile test_script.py

报告主程序运行需要1.662秒。

python -m cProfile test_script.py

报告主程序运行需要0.143秒。

这说明你启动性能分析器的方式和你看到的cProfile与profile之间的差异没有关系。差异是因为这两个性能分析器处理“事件”（比如函数调用或返回）的方式不同。在这两种情况下，你的代码中都有一些软件钩子，会触发回调来跟踪这些事件，并做一些事情，比如更新事件计数器和启动或停止计时器。不过，profile模块是用Python本身来处理这些事件的，这意味着你的解释器需要离开你的代码，执行回调的内容，然后再返回继续执行你的代码。

对于cProfile来说，也需要执行性能分析的回调，但因为这些回调是用C语言写的，所以速度要快得多。看看这两个模块文件profile.py和cProfile.py，你会发现一些不同之处：

1. profile.py有610行，而cProfile.py只有199行——大部分功能都是用C处理的。
2. profile.py主要使用Python库，而cProfile.py导入了一个C代码文件“_lsprof”。源代码可以在这里查看。
3. Profile类在profile.py中没有继承任何其他类（第111行），而cProfile.py中的Profile类（第66行）是从_lsprof.Profiler继承的，这个是在C源文件中实现的。

正如文档所说，cProfile通常是更好的选择，因为它大部分是用C实现的，所以速度更快。

顺便提一下，你可以通过校准来提高profile的性能。关于如何做的详细信息可以在文档中找到。关于这些内容的更多细节，可以参考Python文档中关于确定性分析和限制的部分。

总结

cProfile要快得多，因为顾名思义，它大部分是用C实现的。而profile模块则需要用Python本身来处理所有的性能分析回调。无论你是从命令行调用性能分析器，还是在脚本中手动调用，都不会影响这两个模块之间的时间差异。