Risultati cProfile di Python: due numeri per ncalls

Question

Ho appena iniziato a profilare un'applicazione server su cui ho lavorato, cercando di scoprire dove è stato speso un po 'di tempo in eccesso per il processore e cercando modi per rendere le cose più agevoli.

Nel complesso, penso di avere una buona idea di usare cProfile e pstats, ma non capisco come alcune funzioni elencino due numeri nella colonna ncalls.

Ad esempio, nei risultati seguenti, perché sono elencati due numeri per tutti gli elementi 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

Il numero più piccolo è il numero di chiamate "primitive" o non ricorsive. Il numero maggiore è il numero totale di invocazioni, comprese le chiamate ricorsive. Poiché deepcopy è implementato in modo ricorsivo, significa che hai chiamato deepcopy direttamente 1724 volte, ma che ha finito per chiamarsi ~ 383 k volte per copiare oggetti secondari.