Profiler.pm
NAME
Communiware::Profiler - profiling system for something
SYNOPSYS
use Communiware::Profiler; my $profiler; $profiler = new Communiware::Profiler(mode=>$cgi->param(PROFILE));
sub tested { my $nested = $profiler->nested('prepare') if $profiler; ... some profiled code subtested(args); ... some profiled code $nested->phase('execute') if $nested; ... some profiled code subtested2(args) $nested->phase('cleanup') if $nested; ... some profiled code }
sub subtested { my $nested = $profiler->nested if $profiler; ... some profiled code subtested2(args); ... some profiled code undef $nested; ... some not profiled (as nested) code }
sub subtested2 { my $nested1 = $profiler->nested('','subtested2') if $profiler; ... some profiled as nested1 code { my $nested2 = $nested1->nested('','subtested3') if $nested1 ... some profiled as nested2 code $nested2->handled($sth->rows) if $nested2; } }
tested();
if ($profiler) { my $result = $profiler->statistics; foreach my $id (sort keys(%$result)) { foreach my $phase (qw(prepare execute fetch cleanup)) { print "$id: " . $result->{$id}{$phase}[0] . " times, " . $result->{$id}{$phase}[1] . " sec pure, " . $result->{$id}{$phase}[2] . " sec total.\n"; } } }
DESCRIPTION
This module is intended for profiling perl code with accounting for sub-calls.
Profiling some code chunk, you call nested
as a method of any profiler
object in the stack at the start of every its iteration, optionally supplying a
phase of that chunk and an identifier for it. If you are profiling a whole
function or only one chunk in this function, you can omit the identifier, and
it will be the full name of the function. Omitted or logically false phase is
interpreted as execute
. Iteration will be counted. When you change a phase
(you end with preparation of something and want to execute it), you call the
phase
method of currently running profiler object. If one phase can somhow
handle many uniform items (not necessarily Communiware items) and you are
interested in their total, you can call handled
method while in this phase
supplying it with the number of items handled during this iteration. At the end
of iteration you undef
that profiler or let it to go out of the scope (that
is, if a nested profiled is lexical variable, you usually can safely return
or die
), and profiler will count ``pure'' and ``total'' time of its execution.
``Pure'' means time of execution minus the time of nested profiled iterations.
``Total'' means the time elapsed from the start to the end of iteration.
When you are done, you call statistics
that returns you reference to
statistics hash that maps iteration identifier and a phase to anonymous array
of three elements: number of (started) iterations, total of ``pure'' execution
time for all these iterations, total of ``total'' execution time for all these
iterations. A call for total_time
gives you a total time of execution under
the most outer profiler.
FUNCTIONS
new
$profiler = new Communiware::Profiler(mode => $mode, root_id => $root_id);
Creates new profiler object. Parameters:
mode
-
If true, a main profiler object will be created, otherwise returns
undef
. If 2, identifiers for statistics will trace profiler stack. That is, if it is 1 in the example above you will get total for allsubtested2()
calls as one entry while if it is 2 you will get different totals fortested->subtested->subtested2
andtested->subtested2
calls (and the same for subtested3). Default is false. root_id
- identifier of root code fragment. By default - 'root'.
nested
my $nested = $profiler->nested([phase[, identifier]]);
Creates nested profiler object for profiling iteration and starts specified phase in specified identifier. Parameters:
phase
-
Timing for this phase is started. Phases cannot intersect and do not nest, but
they can interleave if you need it (usually you don't). See phase for
standard phases. Default is
execute
. identifier
- Identifier (or its local part if tracecalls is true) for collecting statistics. Default is current function name.
phase
$profiler->phase($phase_name);
Stops current phase and starts a new phase for $profiler
. Dies if it is not
a currently running profiler. Statistics for previous phase is collected and a
counter for the new phase is incremented. Standard phases are
prepare
- Any preparation (parsing for template, parsing and call to prepare for filter and so on).
execute
- Any execution (executing for template, call to execute for filter).
fetch
- Any fetch of needed data from storage (calls to fetch for filter). Has no sense for other types of activity.
cleanup
- Any cleanup (unrolling stacks, fetching tails from storage, and so on)
handled
$profiler->handled($nitems);
Adds number of items handled (usually rows fetched) on this phase into statistics.
statistics
$hashref = $profiler->statistics; $hashref = $profiler->statistics([Time::HiRes::gettimeofday()]);
Returns collected statistics. WARNING: This call STOPS collecting statistics
(at a specified moment or now). Dies if collecting is running, that is, if
$profiler
is nested or has a non-trivial stack.
Returned value is the reference to hash
(id => { phase => [count,pure_time,total_time], ...}, ...)
.
total_time
my $seconds = $profiler->total_time; my $seconds = $profiler->total_time([Time::HiRes::gettimeofday()]);
Returns total time of profiler execution from its initialization up to now or specified moment.
Internal functions
_pause
$top->_pause($t, $frame);
Pauses accounting for a specified by $frame
stacked profiler at <$t>. That
is, netto time is collected into statistics and cleared.
DESTROY
undef $profiler;
Stops accounting for a specified profiler. That is, netto and brutto times are collected into statistics and stack is unrolled by one.