Menu
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) 
974
The syntax is cProfile. run(statement, filename=None, sort=-1) . You can pass python code or a function name that you want to profile as a string to the statement argument. If you want to save the output in a file, it can be passed to the filename argument.
We define primitive to mean that the call was not induced via recursion. ...when the function does not recurse, these two values are the same. Sorting by calls or ncalls is the same.
Introduction to the profilers cProfile and profile provide deterministic profiling of Python programs. A profile is a set of statistics that describes how often and for how long various parts of the program executed. These statistics can be formatted into reports via the pstats module.
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.
166
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
