Результаты Python cProfile: два числа для ncalls


Я только недавно начал профилировать серверное приложение, над которым я работал, пытаясь выяснить, где тратится некоторое избыточное процессорное время, и искать способы сделать вещи более гладкими.

В целом, я думаю, что у меня есть хороший навык использования cProfile и pstats, но я не понимаю, как некоторые функции перечисляют два числа в столбце ncalls.

Например, в приведенных ниже результатах, почему для всех копий указаны два числа.глубинная микроскопия?

         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)
1 11

1 ответ:

Меньшее число - это число "примитивных" или нерекурсивных вызовов. Большее число-это общее число вызовов, включая рекурсивные вызовы. Поскольку deepcopy реализована рекурсивно, это означает, что вы вызывали deepcopy напрямую 1724 раза, но в итоге он вызывал сам себя ~383k раз для копирования подобъектов.