[Zope] ZopeProfiler (python profiler) - strange results

[Dieter Maurer]

Maciej Wisniowski wrote at 2005-7-19 23:31 +0200:
> ...
>This seemed good till I've used "print_callees" format which
>showed me that function X is calling function Y and Z and
>their execution times are:
>
>functions_time = Y_call_time + Z_call_time.
>
>
>As far as I understand it "tottime" is the time without
>subfunctions' call times and "cumtime" is with subfunctions'
>call times, so I supposed that:
>
>cumulative_x - functions_time = total_x
>
>but this is not true... in almost every case I've checked it is
>rather:
>
>total_x + functions_time > cumulative_x
>
>Why?

The complete calling statistics is very complex.
Therefore, the profiler does not record the complete information
but only summary information.

Especially, it only records the time spend in a given function (say "X")
but not the different times when "X" is called in different
contexts (e.g. by "A" and "B").
As a consequence, the timings given by the "callees" view are usually
too large for the given context (they show the "X" is called by "A"
but the time given for "X" is the total time spend during any call of
"X" and not only any call from "A").

-- 
Dieter