Python cProfile 结果：ncalls 的两个数字

Question

我最近开始对我正在开发的服务器应用程序进行性能分析，想找出一些多余的处理器时间是怎么花掉的，并寻找让程序运行得更顺畅的方法。

总体来说，我觉得我已经掌握了如何使用cProfile和pstats，但我不太明白为什么有些函数在ncalls这一列里会列出两个数字。

比如，在下面的结果中，为什么所有关于copy.deepcopy的内容都有两个数字呢？

         2892482 function calls (2476782 primitive calls) in 5.952 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       27    0.015    0.001    5.229    0.194 /usr/local/lib/python2.7/twisted/internet/base.py:762(runUntilCurrent)
        7    0.000    0.000    3.109    0.444 /usr/local/lib/python2.7/twisted/internet/task.py:201(__call__)
        7    0.000    0.000    3.109    0.444 /usr/local/lib/python2.7/twisted/internet/defer.py:113(maybeDeferred)
        5    0.000    0.000    2.885    0.577 defs/1sec.def:3690(onesec)
        5    2.100    0.420    2.885    0.577 defs/1sec.def:87(loop)
     1523    0.579    0.000    2.105    0.001 defs/cactions.def:2(cActions)
384463/1724    0.474    0.000    1.039    0.001 /usr/local/lib/python2.7/copy.py:145(deepcopy)
33208/1804    0.147    0.000    1.018    0.001 /usr/local/lib/python2.7/copy.py:226(_deepcopy_list)
17328/15780    0.105    0.000    0.959    0.000 /usr/local/lib/python2.7/copy.py:253(_deepcopy_dict)

Answer 1

较小的数字是指“原始”调用的次数，也就是那些不涉及递归的调用次数。较大的数字则是所有调用的总和，包括递归调用。因为深拷贝（deepcopy）是通过递归实现的，这意味着你直接调用深拷贝的次数是1724次，但它实际上为了复制子对象，自己又调用了大约383,000次。