澄清pstats模块的输出

Question

我在我的代码上运行了cProfile，得到了以下结果：

% stats 10
     646493 function calls (524209 primitive calls) in 3.606 CPU seconds

Ordered by: cumulative time
List reduced from 260 to 10 due to restriction <10>

ncalls   tottime  percall  cumtime  percall filename:lineno(function)
     1     0.000    0.000    3.606    3.606 <string>:1(<module>)
     1     0.007    0.007    3.606    3.606 {execfile}
     1     0.068    0.068    3.599    3.599 example.py:7(<module>)
     3     0.000    0.000    3.266    1.089 tree.py:1058(parseString)
6698/3     0.068    0.000    3.244    1.081 tree.py:2406(do_parse3)
104813/3   1.084    0.000    3.244    1.081 tree.py:926(_nocache)
2615/3     0.016    0.000    3.243    1.081 tree.py:2679(internal_parse)
3602/14    0.712    0.000    3.239    0.231 tree.py:2531(do_parse2)
  13/8     0.000    0.000    3.229    0.404 tree.py:2876(do_parse)
2546/20    0.024    0.000    3.218    0.161 tree.py:1003(parse)

根据文档，

我们把“原始调用”定义为没有通过递归引起的调用。

那么我可以安全地得出结论，我的代码慢的原因是：

1. 因为有122284次递归调用。
2. 最大的递归方法是 do_parse3 和 _nocache。
3. 原始调用不重要，无法进一步优化。

Answer 1

1. 我觉得你无法判断时间花费是因为方法调用的原因，还是因为这些方法内部的工作。

2. 我同意。这里是开始微优化Python代码的地方。这样做可能会让你的代码运行得更快，但通常还有更好的方法来加速某个特定的任务。

3. 其实不然。首先，如果你有一个真实的应用，这会显示出你可能想要去掉的调用。我看到你在个人资料里提到这个调用被执行了三次；也许它在做同样的计算三次，而（子）结果可以被缓存。也许原始的（基础）调用可以做一些事情来减少子任务需要完成的工作量。

我建议你看看调用图。为此我使用Gprof2Dot工具：

gprof2dot.py -f pstats tmp.pstats | dot -Tpng -o tmp.png

http://code.google.com/p/jrfonseca/wiki/Gprof2Dot
http://maxy.homeip.net/misc/gprof2dot_example.png