wyniki Python cProfile: dwa numery do ncalls

Question

Właśnie niedawno rozpoczęły profilowania aplikacji serwera, że ​​pracuję dalej, próbuje dowiedzieć się, gdzie niektóre nadmiar czasu procesora są wydawane i szuka sposobów, aby rzeczy gładsza.

Ogólnie rzecz biorąc, myślę, że mam dobrą znajomość używania cProfile i pstats, ale nie rozumiem, jak niektóre funkcje zawierają dwie liczby w kolumnie ncalls.

Na przykład, w poniższych wynikach, dlaczego są tam dwa numery wymienione wszystkie rzeczy 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

Mniejsza liczba to liczba połączeń "pierwotnych" lub nierekurencyjnych. Większa liczba to całkowita liczba wywołań, w tym wywołań rekursywnych. Ponieważ deepcopy jest zaimplementowane rekurencyjnie, oznacza to, że wywołałeś deepcopy bezpośrednio 1724 razy, ale to zakończyło się wywoływaniem ~ 383k razy, aby skopiować sub-obiekty.