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 all subtested2() calls as one entry while if it is 2 you will get different totals for tested->subtested->subtested2 and tested->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.

16 октябрь 2007 13:45