MirOS Manual: Devel::DProf(3p)


ext::Devel::DProfPerlrProgrammers Refext::Devel::DProf::DProf(3p)

NAME

     Devel::DProf - a Perl code profiler

SYNOPSIS

             perl -d:DProf test.pl

DESCRIPTION

     The Devel::DProf package is a Perl code profiler.  This will
     collect information on the execution time of a Perl script
     and of the subs in that script.  This information can be
     used to determine which subroutines are using the most time
     and which subroutines are being called most often.  This
     information can also be used to create an execution graph of
     the script, showing subroutine relationships.

     To profile a Perl script run the perl interpreter with the
     -d debugging switch.  The profiler uses the debugging hooks.
     So to profile script test.pl the following command should be
     used:

             perl -d:DProf test.pl

     When the script terminates (or when the output buffer is
     filled) the profiler will dump the profile information to a
     file called tmon.out.  A tool like dprofpp can be used to
     interpret the information which is in that profile.  The
     following command will print the top 15 subroutines which
     used the most time:

             dprofpp

     To print an execution graph of the subroutines in the script
     use the following command:

             dprofpp -T

     Consult dprofpp for other options.

PROFILE FORMAT

     The old profile is a text file which looks like this:

perl v5.8.8                2005-02-05                           1

ext::Devel::DProfPerlrProgrammers Refext::Devel::DProf::DProf(3p)

             #fOrTyTwO
             $hz=100;
             $XS_VERSION='DProf 19970606';
             # All values are given in HZ
             $rrun_utime=2; $rrun_stime=0; $rrun_rtime=7
             PART2
             + 26 28 566822884 DynaLoader::import
             - 26 28 566822884 DynaLoader::import
             + 27 28 566822885 main::bar
             - 27 28 566822886 main::bar
             + 27 28 566822886 main::baz
             + 27 28 566822887 main::bar
             - 27 28 566822888 main::bar
             [....]

     The first line is the magic number.  The second line is the
     hertz value, or clock ticks, of the machine where the pro-
     file was collected.  The third line is the name and version
     identifier of the tool which created the profile. The fourth
     line is a comment.  The fifth line contains three variables
     holding the user time, system time, and realtime of the pro-
     cess while it was being profiled.  The sixth line indicates
     the beginning of the sub entry/exit profile section.

     The columns in PART2 are:

             sub entry(+)/exit(-) mark
             app's user time at sub entry/exit mark, in ticks
             app's system time at sub entry/exit mark, in ticks
             app's realtime at sub entry/exit mark, in ticks
             fully-qualified sub name, when possible

     With newer perls another format is used, which may look like
     this:

             #fOrTyTwO
             $hz=10000;
             $XS_VERSION='DProf 19971213';
             # All values are given in HZ
             $over_utime=5917; $over_stime=0; $over_rtime=5917;
             $over_tests=10000;
             $rrun_utime=1284; $rrun_stime=0; $rrun_rtime=1284;
             $total_marks=6;

perl v5.8.8                2005-02-05                           2

ext::Devel::DProfPerlrProgrammers Refext::Devel::DProf::DProf(3p)

             PART2
             @ 406 0 406
             & 2 main bar
             + 2
             @ 456 0 456
             - 2
             @ 1 0 1
             & 3 main baz
             + 3
             @ 141 0 141
             + 2
             @ 141 0 141
             - 2
             @ 1 0 1
             & 4 main foo
             + 4
             @ 142 0 142
             + & Devel::DProf::write
             @ 5 0 5
             - & Devel::DProf::write

     (with high value of $ENV{PERL_DPROF_TICKS}).

     New "$over_*" values show the measured overhead of making
     $over_tests calls to the profiler These values are used by
     the profiler to subtract the overhead from the runtimes.

     The lines starting with "@" mark time passed from the previ-
     ous "@" line.  The lines starting with "&" introduce new
     subroutine id and show the package and the subroutine name
     of this id.  Lines starting with "+", "-" and "*" mark
     entering and exit of subroutines by ids, and "goto &subr".

     The old-style "+"- and "-"-lines are used to mark the over-
     head related to writing to profiler-output file.

AUTOLOAD

     When Devel::DProf finds a call to an &AUTOLOAD subroutine it
     looks at the $AUTOLOAD variable to find the real name of the
     sub being called.  See "Autoloading" in perlsub.

ENVIRONMENT

     "PERL_DPROF_BUFFER" sets size of output buffer in words.
     Defaults to 2**14.

     "PERL_DPROF_TICKS" sets number of ticks per second on some
     systems where a replacement for times() is used.  Defaults
     to the value of "HZ" macro.

     "PERL_DPROF_OUT_FILE_NAME" sets the name of the output file.
     If not set, defaults to tmon.out.

perl v5.8.8                2005-02-05                           3

ext::Devel::DProfPerlrProgrammers Refext::Devel::DProf::DProf(3p)

BUGS

     Builtin functions cannot be measured by Devel::DProf.

     With a newer Perl DProf relies on the fact that the numeric
     slot of $DB::sub contains an address of a subroutine.
     Excessive manipulation of this variable may overwrite this
     slot, as in

       $DB::sub = 'current_sub';
       ...
       $addr = $DB::sub + 0;

     will set this numeric slot to numeric value of the string
     "current_sub", i.e., to 0.  This will cause a segfault on
     the exit from this subroutine.  Note that the first assign-
     ment above does not change the numeric slot (it will mark it
     as invalid, but will not write over it).

     Another problem is that if a subroutine exits using
     goto(LABEL), last(LABEL) or next(LABEL) then perl may crash
     or Devel::DProf will die with the error:

        panic: Devel::DProf inconsistent subroutine return

     For example, this code will break under Devel::DProf:

        sub foo {
          last FOO;
        }
        FOO: {
          foo();
        }

     A pattern like this is used by Test::More's skip() function,
     for example.  See perldiag for more details.

     Mail bug reports and feature requests to the perl5-porters
     mailing list at <perl5-porters@perl.org>.

SEE ALSO

     perl, dprofpp, times(2)

perl v5.8.8                2005-02-05                           4

Generated on 2014-07-04 21:17:45 by $MirOS: src/scripts/roff2htm,v 1.79 2014/02/10 00:36:11 tg Exp $

These manual pages and other documentation are copyrighted by their respective writers; their source is available at our CVSweb, AnonCVS, and other mirrors. The rest is Copyright © 2002‒2014 The MirOS Project, Germany.
This product includes material provided by Thorsten Glaser.

This manual page’s HTML representation is supposed to be valid XHTML/1.1; if not, please send a bug report – diffs preferred.