Commit | Line | Data |
17f410f9 |
1 | require 5.005_64; |
583a019e |
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 | |
34445a8a |
136 | C<PERL_DPROF_OUT_FILE_NAME> sets the name of the output file. If not set, |
137 | defaults to tmon.out. |
138 | |
583a019e |
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 | |
9426adcd |
188 | use XSLoader (); |
189 | |
117c97cc |
190 | # Underscore to allow older Perls to access older version from CPAN |
191 | $Devel::DProf::VERSION = '20000000.00_00'; # this version not authorized by |
583a019e |
192 | # Dean Roehrich. See "Changes" file. |
193 | |
9426adcd |
194 | XSLoader::load 'Devel::DProf', $Devel::DProf::VERSION; |
583a019e |
195 | |
196 | 1; |