ext/Devel/DProf/DProf.pm

   1 require 5.003;
   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 Mail bug reports and feature requests to the perl5-porters mailing list at
 158 F<E<lt>perl5-porters@perl.orgE<gt>>.
 159
 160 =head1 SEE ALSO
 161
 162 L<perl>, L<dprofpp>, times(2)
 163
 164 =cut
 165
 166 # This sub is needed for calibration.
 167 package Devel::DProf;
 168
 169 sub NONESUCH_noxs {
 170         return $Devel::DProf::VERSION;
 171 }
 172
 173 package DB;
 174
 175 #
 176 # As of perl5.003_20, &DB::sub stub is not needed (some versions
 177 # even had problems if stub was redefined with XS version).
 178 #
 179
 180 # disable DB single-stepping
 181 BEGIN { $single = 0; }
 182
 183 # This sub is needed during startup.
 184 sub DB {
 185 #       print "nonXS DBDB\n";
 186 }
 187
 188 use XSLoader ();
 189
 190 $Devel::DProf::VERSION = '19990108'; # this version not authorized by
 191                                      # Dean Roehrich. See "Changes" file.
 192
 193 XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION;
 194
 195 1;