What is the difference between tottime and cumtime on cProfile output?

Question

I am profiling a python script main.py using cProfile with the following command:

python -m cProfile -s tottime main.py 

The output I get is (only copy-pasted the top lines of the output):

10184337 function calls (10181667 primitive calls) in 13.597 seconds  Ordered by: internal time  ncalls  tottime  percall  cumtime  percall filename:lineno(function)     1    4.674    4.674   13.598   13.598 main.py:2(<module>)  2142    2.964    0.001    4.663    0.002 load_aerdat3.py:61(getPacket)   459    2.381    0.005    2.381    0.005 {waitKey} 1667989    1.170    0.000    1.170    0.000 {numpy.core.multiarray.array}  ... 

How can the tottime (4.674) be different from the cumtime (13.598) for main.py, since this function (ie. the whole script) is only called once?

Answer 1

tottime is the total time spent in the function alone. cumtime is the total time spent in the function plus all functions that this function called.

The two values is going to be the same if a function never calls anything else. For example, {waitKey} doesn't appear to invoke anything else:

  459    2.381    0.005    2.381    0.005 {waitKey} 

but getPacket() calls other functions, so it's cumtime column includes the time for those calls:

 2142    2.964    0.001    4.663    0.002 load_aerdat3.py:61(getPacket) 

The main.py line covers all code run outside of functions, the global code; just the statements at that level took 4.674 seconds to run, but because those statements called other functions, the total cumulative time of the main.py code plus all function calls made is 13.598 seconds.

From the documentation:

tottime
for the total time spent in the given function (and excluding time made in calls to sub-functions)

[...]

cumtime
is the cumulative time spent in this and all subfunctions (from invocation till exit). This figure is accurate even for recursive functions.