41

I just recently began profiling a server application that I've been working on, trying to find out where some excess processor time is being spent and looking for ways to make things smoother.

Overall, I think I've got a good hang of using cProfile and pstats, but I don't understand how some of functions list two numbers in the ncalls column.

For example, in the below results, why are there two numbers listed for all the copy.deepcopy stuff?

         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)
Andrew Baird
  • 413
  • 4
  • 5

1 Answers1

49

The smaller number is the number of 'primitive' or non-recursive calls. The larger number is the total number of invocations, including recursive calls. Since deepcopy is implemented recursively, it means that you called deepcopy directly 1724 times, but that it ended up calling itself ~383k times to copy sub-objects.

Evan
  • 2,217
  • 15
  • 18
  • 5
    Thanks. This matches up with what I found at https://docs.python.org/2/library/profile.html#instant-user-s-manual ... That frustrating moment when you ask a question and then find the answer a couple minutes later with further digging around. I couldn't respond to my own post since I've never actually posted on this site before and have under 10 rep. – Andrew Baird Apr 11 '14 at 18:10
  • It's also in the Python 3 docs: https://docs.python.org/3/library/profile.html#instant-user-s-manual – AlexM May 25 '23 at 15:16