This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
Provide fallback implementation of getaddrinfo and getnameinfo in pure perl if libc...
[perl5.git] / ext / Devel-DProf / DProf.pm
CommitLineData
3b825e41 1use 5.006_001;
583a019e
GS
2
3=head1 NAME
4
5Devel::DProf - a Perl code profiler
6
7=head1 SYNOPSIS
8
7d2f1258 9 perl -d:DProf test.pl
583a019e
GS
10
11=head1 DESCRIPTION
12
13The Devel::DProf package is a Perl code profiler. This will collect
14information on the execution time of a Perl script and of the subs in that
15script. This information can be used to determine which subroutines are
16using the most time and which subroutines are being called most often. This
17information can also be used to create an execution graph of the script,
18showing subroutine relationships.
19
20To profile a Perl script run the perl interpreter with the B<-d> debugging
21switch. The profiler uses the debugging hooks. So to profile script
22F<test.pl> the following command should be used:
23
7d2f1258 24 perl -d:DProf test.pl
583a019e
GS
25
26When the script terminates (or when the output buffer is filled) the
27profiler will dump the profile information to a file called
28F<tmon.out>. A tool like I<dprofpp> can be used to interpret the
29information which is in that profile. The following command will
30print the top 15 subroutines which used the most time:
31
32 dprofpp
33
34To print an execution graph of the subroutines in the script use the
35following command:
36
37 dprofpp -T
38
39Consult L<dprofpp> for other options.
40
41=head1 PROFILE FORMAT
42
43The 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
60The first line is the magic number. The second line is the hertz value, or
61clock ticks, of the machine where the profile was collected. The third line
62is the name and version identifier of the tool which created the profile.
63The fourth line is a comment. The fifth line contains three variables
64holding the user time, system time, and realtime of the process while it was
65being profiled. The sixth line indicates the beginning of the sub
66entry/exit profile section.
67
68The 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
76With 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
110New C<$over_*> values show the measured overhead of making $over_tests
111calls to the profiler These values are used by the profiler to
112subtract the overhead from the runtimes.
113
a1bbeb14
GA
114Lines starting with C<@> mark the amount of time passed since the
115previous C<@> line. The numbers following the C<@> are integer tick
116counts representing user, system, and real time. Divide these numbers
117by the $hz value in the header to get seconds.
118
119Lines starting with C<&> map subroutine identifiers (an integer) to
120subroutine packages and names. These should only occur once per
121subroutine.
122
123Lines starting with C<+> or C<-> mark normal entering and exit of
124subroutines. The number following is a reference to a subroutine
125identifier.
126
127Lines starting with C<*> mark where subroutines are entered by C<goto
128&subr>, but note that the return will still be marked as coming from
129the original sub. The sequence might look like this:
130
131 + 5
132 * 6
133 - 5
134
135Lines starting with C</> is like C<-> but mark where subroutines are
136exited by dying. Example:
137
138 + 5
139 + 6
140 / 6
141 / 5
142
143Finally you might find C<@> time stamp marks surrounded by C<+ &
144Devel::DProf::write> and C<- & Devel::DProf::write> lines. These 3
145lines are outputted when printing of the mark above actually consumed
146measurable time.
583a019e
GS
147
148=head1 AUTOLOAD
149
150When Devel::DProf finds a call to an C<&AUTOLOAD> subroutine it looks at the
151C<$AUTOLOAD> variable to find the real name of the sub being called. See
152L<perlsub/"Autoloading">.
153
154=head1 ENVIRONMENT
155
156C<PERL_DPROF_BUFFER> sets size of output buffer in words. Defaults to 2**14.
157
158C<PERL_DPROF_TICKS> sets number of ticks per second on some systems where
159a replacement for times() is used. Defaults to the value of C<HZ> macro.
160
34445a8a
GS
161C<PERL_DPROF_OUT_FILE_NAME> sets the name of the output file. If not set,
162defaults to tmon.out.
163
583a019e
GS
164=head1 BUGS
165
166Builtin functions cannot be measured by Devel::DProf.
167
168With a newer Perl DProf relies on the fact that the numeric slot of
169$DB::sub contains an address of a subroutine. Excessive manipulation
170of this variable may overwrite this slot, as in
171
172 $DB::sub = 'current_sub';
173 ...
174 $addr = $DB::sub + 0;
175
176will set this numeric slot to numeric value of the string
177C<current_sub>, i.e., to C<0>. This will cause a segfault on the exit
178from this subroutine. Note that the first assignment above does not
179change the numeric slot (it will I<mark> it as invalid, but will not
180write over it).
181
7619c85e
RG
182Another problem is that if a subroutine exits using goto(LABEL),
183last(LABEL) or next(LABEL) then perl may crash or Devel::DProf will die
184with the error:
185
186 panic: Devel::DProf inconsistent subroutine return
187
188For example, this code will break under Devel::DProf:
189
190 sub foo {
191 last FOO;
192 }
193 FOO: {
194 foo();
195 }
196
197A pattern like this is used by Test::More's skip() function, for
198example. See L<perldiag> for more details.
199
583a019e
GS
200Mail bug reports and feature requests to the perl5-porters mailing list at
201F<E<lt>perl5-porters@perl.orgE<gt>>.
202
203=head1 SEE ALSO
204
205L<perl>, L<dprofpp>, times(2)
206
207=cut
208
209# This sub is needed for calibration.
210package Devel::DProf;
211
212sub NONESUCH_noxs {
213 return $Devel::DProf::VERSION;
214}
215
216package DB;
217
218#
219# As of perl5.003_20, &DB::sub stub is not needed (some versions
220# even had problems if stub was redefined with XS version).
221#
222
223# disable DB single-stepping
224BEGIN { $single = 0; }
225
226# This sub is needed during startup.
227sub DB {
228# print "nonXS DBDB\n";
229}
230
9426adcd
IZ
231use XSLoader ();
232
6f154b1b 233$Devel::DProf::VERSION = '20080331.00'; # this version not authorized by
e9d8cdc0 234 # Dean Roehrich. See "Changes" file.
583a019e 235
9426adcd 236XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION;
583a019e
GS
237
2381;