home *** CD-ROM | disk | FTP | other *** search
/ Netrunner 2004 October / NETRUNNER0410.ISO / regular / ActivePerl-5.8.4.810-MSWin32-x86.msi / _ffc38410895736ab00a0f96be700c20d < prev    next >
Text File  |  2004-06-01  |  6KB  |  214 lines
  1. use 5.006_001;
  2.  
  3. =head1 NAME
  4.  
  5. Devel::DProf - a Perl code profiler
  6.  
  7. =head1 SYNOPSIS
  8.  
  9.     perl5 -d:DProf test.pl
  10.  
  11. =head1 DESCRIPTION
  12.  
  13. The Devel::DProf package is a Perl code profiler.  This will collect
  14. information on the execution time of a Perl script and of the subs in that
  15. script.  This information can be used to determine which subroutines are
  16. using the most time and which subroutines are being called most often.  This
  17. information can also be used to create an execution graph of the script,
  18. showing subroutine relationships.
  19.  
  20. To profile a Perl script run the perl interpreter with the B<-d> debugging
  21. switch.  The profiler uses the debugging hooks.  So to profile script
  22. F<test.pl> the following command should be used:
  23.  
  24.     perl5 -d:DProf test.pl
  25.  
  26. When the script terminates (or when the output buffer is filled) the
  27. profiler will dump the profile information to a file called
  28. F<tmon.out>.  A tool like I<dprofpp> can be used to interpret the
  29. information which is in that profile.  The following command will
  30. print the top 15 subroutines which used the most time:
  31.  
  32.     dprofpp
  33.  
  34. To print an execution graph of the subroutines in the script use the
  35. following command:
  36.  
  37.     dprofpp -T
  38.  
  39. Consult L<dprofpp> for other options.
  40.  
  41. =head1 PROFILE FORMAT
  42.  
  43. The old profile is a text file which looks like this:
  44.  
  45.     #fOrTyTwO
  46.     $hz=100;
  47.     $XS_VERSION='DProf 19970606';
  48.     # All values are given in HZ
  49.     $rrun_utime=2; $rrun_stime=0; $rrun_rtime=7
  50.     PART2
  51.     + 26 28 566822884 DynaLoader::import
  52.     - 26 28 566822884 DynaLoader::import
  53.     + 27 28 566822885 main::bar
  54.     - 27 28 566822886 main::bar
  55.     + 27 28 566822886 main::baz
  56.     + 27 28 566822887 main::bar
  57.     - 27 28 566822888 main::bar
  58.     [....]
  59.  
  60. The first line is the magic number.  The second line is the hertz value, or
  61. clock ticks, of the machine where the profile was collected.  The third line
  62. is the name and version identifier of the tool which created the profile.
  63. The fourth line is a comment.  The fifth line contains three variables
  64. holding the user time, system time, and realtime of the process while it was
  65. being profiled.  The sixth line indicates the beginning of the sub
  66. entry/exit profile section.
  67.  
  68. The columns in B<PART2> are:
  69.  
  70.     sub entry(+)/exit(-) mark
  71.     app's user time at sub entry/exit mark, in ticks
  72.     app's system time at sub entry/exit mark, in ticks
  73.     app's realtime at sub entry/exit mark, in ticks
  74.     fully-qualified sub name, when possible
  75.  
  76. With newer perls another format is used, which may look like this:
  77.  
  78.         #fOrTyTwO
  79.         $hz=10000;
  80.         $XS_VERSION='DProf 19971213';
  81.         # All values are given in HZ
  82.         $over_utime=5917; $over_stime=0; $over_rtime=5917;
  83.         $over_tests=10000;
  84.         $rrun_utime=1284; $rrun_stime=0; $rrun_rtime=1284;
  85.         $total_marks=6;
  86.  
  87.         PART2
  88.         @ 406 0 406
  89.         & 2 main bar
  90.         + 2
  91.         @ 456 0 456
  92.         - 2
  93.         @ 1 0 1
  94.         & 3 main baz
  95.         + 3
  96.         @ 141 0 141
  97.         + 2
  98.         @ 141 0 141
  99.         - 2
  100.         @ 1 0 1
  101.         & 4 main foo
  102.         + 4
  103.         @ 142 0 142
  104.         + & Devel::DProf::write
  105.         @ 5 0 5
  106.         - & Devel::DProf::write
  107.  
  108. (with high value of $ENV{PERL_DPROF_TICKS}).  
  109.  
  110. New C<$over_*> values show the measured overhead of making $over_tests
  111. calls to the profiler These values are used by the profiler to
  112. subtract the overhead from the runtimes.
  113.  
  114. The lines starting with C<@> mark time passed from the previous C<@>
  115. line.  The lines starting with C<&> introduce new subroutine I<id> and
  116. show the package and the subroutine name of this id.  Lines starting
  117. with C<+>, C<-> and C<*> mark entering and exit of subroutines by
  118. I<id>s, and C<goto &subr>.
  119.  
  120. The I<old-style> C<+>- and C<->-lines are used to mark the overhead
  121. related to writing to profiler-output file.
  122.  
  123. =head1 AUTOLOAD
  124.  
  125. When Devel::DProf finds a call to an C<&AUTOLOAD> subroutine it looks at the
  126. C<$AUTOLOAD> variable to find the real name of the sub being called.  See
  127. L<perlsub/"Autoloading">.
  128.  
  129. =head1 ENVIRONMENT
  130.  
  131. C<PERL_DPROF_BUFFER> sets size of output buffer in words.  Defaults to 2**14.
  132.  
  133. C<PERL_DPROF_TICKS> sets number of ticks per second on some systems where
  134. a replacement for times() is used.  Defaults to the value of C<HZ> macro.
  135.  
  136. C<PERL_DPROF_OUT_FILE_NAME> sets the name of the output file.  If not set,
  137. defaults to tmon.out.
  138.  
  139. =head1 BUGS
  140.  
  141. Builtin functions cannot be measured by Devel::DProf.
  142.  
  143. With a newer Perl DProf relies on the fact that the numeric slot of
  144. $DB::sub contains an address of a subroutine.  Excessive manipulation
  145. of this variable may overwrite this slot, as in
  146.  
  147.   $DB::sub = 'current_sub';
  148.   ...
  149.   $addr = $DB::sub + 0;
  150.  
  151. will set this numeric slot to numeric value of the string
  152. C<current_sub>, i.e., to C<0>.  This will cause a segfault on the exit
  153. from this subroutine.  Note that the first assignment above does not
  154. change the numeric slot (it will I<mark> it as invalid, but will not
  155. write over it).
  156.  
  157. Another problem is that if a subroutine exits using goto(LABEL),
  158. last(LABEL) or next(LABEL) then perl may crash or Devel::DProf will die
  159. with the error:
  160.  
  161.    panic: Devel::DProf inconsistent subroutine return
  162.  
  163. For example, this code will break under Devel::DProf:
  164.  
  165.    sub foo {
  166.      last FOO;
  167.    }
  168.    FOO: {
  169.      foo();
  170.    }
  171.  
  172. A pattern like this is used by Test::More's skip() function, for
  173. example.  See L<perldiag> for more details.
  174.  
  175. Mail bug reports and feature requests to the perl5-porters mailing list at
  176. F<E<lt>perl5-porters@perl.orgE<gt>>.
  177.  
  178. =head1 SEE ALSO
  179.  
  180. L<perl>, L<dprofpp>, times(2)
  181.  
  182. =cut
  183.  
  184. # This sub is needed for calibration.
  185. package Devel::DProf;
  186.  
  187. sub NONESUCH_noxs {
  188.     return $Devel::DProf::VERSION;
  189. }
  190.  
  191. package DB;
  192.  
  193. #
  194. # As of perl5.003_20, &DB::sub stub is not needed (some versions
  195. # even had problems if stub was redefined with XS version).
  196. #
  197.  
  198. # disable DB single-stepping
  199. BEGIN { $single = 0; }
  200.  
  201. # This sub is needed during startup.
  202. sub DB { 
  203. #    print "nonXS DBDB\n";
  204. }
  205.  
  206. use XSLoader ();
  207.  
  208. $Devel::DProf::VERSION = '20030813.00';  # this version not authorized by
  209.                          # Dean Roehrich. See "Changes" file.
  210.  
  211. XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION;
  212.  
  213. 1;
  214.