| 1 | .\" Automatically generated by Pod::Man v1.37, Pod::Parser v1.32 |
| 2 | .\" |
| 3 | .\" Standard preamble: |
| 4 | .\" ======================================================================== |
| 5 | .de Sh \" Subsection heading |
| 6 | .br |
| 7 | .if t .Sp |
| 8 | .ne 5 |
| 9 | .PP |
| 10 | \fB\\$1\fR |
| 11 | .PP |
| 12 | .. |
| 13 | .de Sp \" Vertical space (when we can't use .PP) |
| 14 | .if t .sp .5v |
| 15 | .if n .sp |
| 16 | .. |
| 17 | .de Vb \" Begin verbatim text |
| 18 | .ft CW |
| 19 | .nf |
| 20 | .ne \\$1 |
| 21 | .. |
| 22 | .de Ve \" End verbatim text |
| 23 | .ft R |
| 24 | .fi |
| 25 | .. |
| 26 | .\" Set up some character translations and predefined strings. \*(-- will |
| 27 | .\" give an unbreakable dash, \*(PI will give pi, \*(L" will give a left |
| 28 | .\" double quote, and \*(R" will give a right double quote. | will give a |
| 29 | .\" real vertical bar. \*(C+ will give a nicer C++. Capital omega is used to |
| 30 | .\" do unbreakable dashes and therefore won't be available. \*(C` and \*(C' |
| 31 | .\" expand to `' in nroff, nothing in troff, for use with C<>. |
| 32 | .tr \(*W-|\(bv\*(Tr |
| 33 | .ds C+ C\v'-.1v'\h'-1p'\s-2+\h'-1p'+\s0\v'.1v'\h'-1p' |
| 34 | .ie n \{\ |
| 35 | . ds -- \(*W- |
| 36 | . ds PI pi |
| 37 | . if (\n(.H=4u)&(1m=24u) .ds -- \(*W\h'-12u'\(*W\h'-12u'-\" diablo 10 pitch |
| 38 | . if (\n(.H=4u)&(1m=20u) .ds -- \(*W\h'-12u'\(*W\h'-8u'-\" diablo 12 pitch |
| 39 | . ds L" "" |
| 40 | . ds R" "" |
| 41 | . ds C` "" |
| 42 | . ds C' "" |
| 43 | 'br\} |
| 44 | .el\{\ |
| 45 | . ds -- \|\(em\| |
| 46 | . ds PI \(*p |
| 47 | . ds L" `` |
| 48 | . ds R" '' |
| 49 | 'br\} |
| 50 | .\" |
| 51 | .\" If the F register is turned on, we'll generate index entries on stderr for |
| 52 | .\" titles (.TH), headers (.SH), subsections (.Sh), items (.Ip), and index |
| 53 | .\" entries marked with X<> in POD. Of course, you'll have to process the |
| 54 | .\" output yourself in some meaningful fashion. |
| 55 | .if \nF \{\ |
| 56 | . de IX |
| 57 | . tm Index:\\$1\t\\n%\t"\\$2" |
| 58 | .. |
| 59 | . nr % 0 |
| 60 | . rr F |
| 61 | .\} |
| 62 | .\" |
| 63 | .\" For nroff, turn off justification. Always turn off hyphenation; it makes |
| 64 | .\" way too many mistakes in technical documents. |
| 65 | .hy 0 |
| 66 | .if n .na |
| 67 | .\" |
| 68 | .\" Accent mark definitions (@(#)ms.acc 1.5 88/02/08 SMI; from UCB 4.2). |
| 69 | .\" Fear. Run. Save yourself. No user-serviceable parts. |
| 70 | . \" fudge factors for nroff and troff |
| 71 | .if n \{\ |
| 72 | . ds #H 0 |
| 73 | . ds #V .8m |
| 74 | . ds #F .3m |
| 75 | . ds #[ \f1 |
| 76 | . ds #] \fP |
| 77 | .\} |
| 78 | .if t \{\ |
| 79 | . ds #H ((1u-(\\\\n(.fu%2u))*.13m) |
| 80 | . ds #V .6m |
| 81 | . ds #F 0 |
| 82 | . ds #[ \& |
| 83 | . ds #] \& |
| 84 | .\} |
| 85 | . \" simple accents for nroff and troff |
| 86 | .if n \{\ |
| 87 | . ds ' \& |
| 88 | . ds ` \& |
| 89 | . ds ^ \& |
| 90 | . ds , \& |
| 91 | . ds ~ ~ |
| 92 | . ds / |
| 93 | .\} |
| 94 | .if t \{\ |
| 95 | . ds ' \\k:\h'-(\\n(.wu*8/10-\*(#H)'\'\h"|\\n:u" |
| 96 | . ds ` \\k:\h'-(\\n(.wu*8/10-\*(#H)'\`\h'|\\n:u' |
| 97 | . ds ^ \\k:\h'-(\\n(.wu*10/11-\*(#H)'^\h'|\\n:u' |
| 98 | . ds , \\k:\h'-(\\n(.wu*8/10)',\h'|\\n:u' |
| 99 | . ds ~ \\k:\h'-(\\n(.wu-\*(#H-.1m)'~\h'|\\n:u' |
| 100 | . ds / \\k:\h'-(\\n(.wu*8/10-\*(#H)'\z\(sl\h'|\\n:u' |
| 101 | .\} |
| 102 | . \" troff and (daisy-wheel) nroff accents |
| 103 | .ds : \\k:\h'-(\\n(.wu*8/10-\*(#H+.1m+\*(#F)'\v'-\*(#V'\z.\h'.2m+\*(#F'.\h'|\\n:u'\v'\*(#V' |
| 104 | .ds 8 \h'\*(#H'\(*b\h'-\*(#H' |
| 105 | .ds o \\k:\h'-(\\n(.wu+\w'\(de'u-\*(#H)/2u'\v'-.3n'\*(#[\z\(de\v'.3n'\h'|\\n:u'\*(#] |
| 106 | .ds d- \h'\*(#H'\(pd\h'-\w'~'u'\v'-.25m'\f2\(hy\fP\v'.25m'\h'-\*(#H' |
| 107 | .ds D- D\\k:\h'-\w'D'u'\v'-.11m'\z\(hy\v'.11m'\h'|\\n:u' |
| 108 | .ds th \*(#[\v'.3m'\s+1I\s-1\v'-.3m'\h'-(\w'I'u*2/3)'\s-1o\s+1\*(#] |
| 109 | .ds Th \*(#[\s+2I\s-2\h'-\w'I'u*3/5'\v'-.3m'o\v'.3m'\*(#] |
| 110 | .ds ae a\h'-(\w'a'u*4/10)'e |
| 111 | .ds Ae A\h'-(\w'A'u*4/10)'E |
| 112 | . \" corrections for vroff |
| 113 | .if v .ds ~ \\k:\h'-(\\n(.wu*9/10-\*(#H)'\s-2\u~\d\s+2\h'|\\n:u' |
| 114 | .if v .ds ^ \\k:\h'-(\\n(.wu*10/11-\*(#H)'\v'-.4m'^\v'.4m'\h'|\\n:u' |
| 115 | . \" for low resolution devices (crt and lpr) |
| 116 | .if \n(.H>23 .if \n(.V>19 \ |
| 117 | \{\ |
| 118 | . ds : e |
| 119 | . ds 8 ss |
| 120 | . ds o a |
| 121 | . ds d- d\h'-1'\(ga |
| 122 | . ds D- D\h'-1'\(hy |
| 123 | . ds th \o'bp' |
| 124 | . ds Th \o'LP' |
| 125 | . ds ae ae |
| 126 | . ds Ae AE |
| 127 | .\} |
| 128 | .rm #[ #] #H #V #F C |
| 129 | .\" ======================================================================== |
| 130 | .\" |
| 131 | .IX Title "Devel::DProf 3" |
| 132 | .TH Devel::DProf 3 "2001-09-21" "perl v5.8.8" "Perl Programmers Reference Guide" |
| 133 | .SH "NAME" |
| 134 | Devel::DProf \- a Perl code profiler |
| 135 | .SH "SYNOPSIS" |
| 136 | .IX Header "SYNOPSIS" |
| 137 | .Vb 1 |
| 138 | \& perl -d:DProf test.pl |
| 139 | .Ve |
| 140 | .SH "DESCRIPTION" |
| 141 | .IX Header "DESCRIPTION" |
| 142 | The Devel::DProf package is a Perl code profiler. This will collect |
| 143 | information on the execution time of a Perl script and of the subs in that |
| 144 | script. This information can be used to determine which subroutines are |
| 145 | using the most time and which subroutines are being called most often. This |
| 146 | information can also be used to create an execution graph of the script, |
| 147 | showing subroutine relationships. |
| 148 | .PP |
| 149 | To profile a Perl script run the perl interpreter with the \fB\-d\fR debugging |
| 150 | switch. The profiler uses the debugging hooks. So to profile script |
| 151 | \&\fItest.pl\fR the following command should be used: |
| 152 | .PP |
| 153 | .Vb 1 |
| 154 | \& perl -d:DProf test.pl |
| 155 | .Ve |
| 156 | .PP |
| 157 | When the script terminates (or when the output buffer is filled) the |
| 158 | profiler will dump the profile information to a file called |
| 159 | \&\fItmon.out\fR. A tool like \fIdprofpp\fR can be used to interpret the |
| 160 | information which is in that profile. The following command will |
| 161 | print the top 15 subroutines which used the most time: |
| 162 | .PP |
| 163 | .Vb 1 |
| 164 | \& dprofpp |
| 165 | .Ve |
| 166 | .PP |
| 167 | To print an execution graph of the subroutines in the script use the |
| 168 | following command: |
| 169 | .PP |
| 170 | .Vb 1 |
| 171 | \& dprofpp -T |
| 172 | .Ve |
| 173 | .PP |
| 174 | Consult dprofpp for other options. |
| 175 | .SH "PROFILE FORMAT" |
| 176 | .IX Header "PROFILE FORMAT" |
| 177 | The old profile is a text file which looks like this: |
| 178 | .PP |
| 179 | .Vb 14 |
| 180 | \& #fOrTyTwO |
| 181 | \& $hz=100; |
| 182 | \& $XS_VERSION='DProf 19970606'; |
| 183 | \& # All values are given in HZ |
| 184 | \& $rrun_utime=2; $rrun_stime=0; $rrun_rtime=7 |
| 185 | \& PART2 |
| 186 | \& + 26 28 566822884 DynaLoader::import |
| 187 | \& - 26 28 566822884 DynaLoader::import |
| 188 | \& + 27 28 566822885 main::bar |
| 189 | \& - 27 28 566822886 main::bar |
| 190 | \& + 27 28 566822886 main::baz |
| 191 | \& + 27 28 566822887 main::bar |
| 192 | \& - 27 28 566822888 main::bar |
| 193 | \& [....] |
| 194 | .Ve |
| 195 | .PP |
| 196 | The first line is the magic number. The second line is the hertz value, or |
| 197 | clock ticks, of the machine where the profile was collected. The third line |
| 198 | is the name and version identifier of the tool which created the profile. |
| 199 | The fourth line is a comment. The fifth line contains three variables |
| 200 | holding the user time, system time, and realtime of the process while it was |
| 201 | being profiled. The sixth line indicates the beginning of the sub |
| 202 | entry/exit profile section. |
| 203 | .PP |
| 204 | The columns in \fB\s-1PART2\s0\fR are: |
| 205 | .PP |
| 206 | .Vb 5 |
| 207 | \& sub entry(+)/exit(-) mark |
| 208 | \& app's user time at sub entry/exit mark, in ticks |
| 209 | \& app's system time at sub entry/exit mark, in ticks |
| 210 | \& app's realtime at sub entry/exit mark, in ticks |
| 211 | \& fully-qualified sub name, when possible |
| 212 | .Ve |
| 213 | .PP |
| 214 | With newer perls another format is used, which may look like this: |
| 215 | .PP |
| 216 | .Vb 8 |
| 217 | \& #fOrTyTwO |
| 218 | \& $hz=10000; |
| 219 | \& $XS_VERSION='DProf 19971213'; |
| 220 | \& # All values are given in HZ |
| 221 | \& $over_utime=5917; $over_stime=0; $over_rtime=5917; |
| 222 | \& $over_tests=10000; |
| 223 | \& $rrun_utime=1284; $rrun_stime=0; $rrun_rtime=1284; |
| 224 | \& $total_marks=6; |
| 225 | .Ve |
| 226 | .PP |
| 227 | .Vb 20 |
| 228 | \& PART2 |
| 229 | \& @ 406 0 406 |
| 230 | \& & 2 main bar |
| 231 | \& + 2 |
| 232 | \& @ 456 0 456 |
| 233 | \& - 2 |
| 234 | \& @ 1 0 1 |
| 235 | \& & 3 main baz |
| 236 | \& + 3 |
| 237 | \& @ 141 0 141 |
| 238 | \& + 2 |
| 239 | \& @ 141 0 141 |
| 240 | \& - 2 |
| 241 | \& @ 1 0 1 |
| 242 | \& & 4 main foo |
| 243 | \& + 4 |
| 244 | \& @ 142 0 142 |
| 245 | \& + & Devel::DProf::write |
| 246 | \& @ 5 0 5 |
| 247 | \& - & Devel::DProf::write |
| 248 | .Ve |
| 249 | .PP |
| 250 | (with high value of \f(CW$ENV\fR{\s-1PERL_DPROF_TICKS\s0}). |
| 251 | .PP |
| 252 | New \f(CW\*(C`$over_*\*(C'\fR values show the measured overhead of making \f(CW$over_tests\fR |
| 253 | calls to the profiler These values are used by the profiler to |
| 254 | subtract the overhead from the runtimes. |
| 255 | .PP |
| 256 | The lines starting with \f(CW\*(C`@\*(C'\fR mark time passed from the previous \f(CW\*(C`@\*(C'\fR |
| 257 | line. The lines starting with \f(CW\*(C`&\*(C'\fR introduce new subroutine \fIid\fR and |
| 258 | show the package and the subroutine name of this id. Lines starting |
| 259 | with \f(CW\*(C`+\*(C'\fR, \f(CW\*(C`\-\*(C'\fR and \f(CW\*(C`*\*(C'\fR mark entering and exit of subroutines by |
| 260 | \&\fIid\fRs, and \f(CW\*(C`goto &subr\*(C'\fR. |
| 261 | .PP |
| 262 | The \fIold-style\fR \f(CW\*(C`+\*(C'\fR\- and \f(CW\*(C`\-\*(C'\fR\-lines are used to mark the overhead |
| 263 | related to writing to profiler-output file. |
| 264 | .SH "AUTOLOAD" |
| 265 | .IX Header "AUTOLOAD" |
| 266 | When Devel::DProf finds a call to an \f(CW&AUTOLOAD\fR subroutine it looks at the |
| 267 | \&\f(CW$AUTOLOAD\fR variable to find the real name of the sub being called. See |
| 268 | \&\*(L"Autoloading\*(R" in perlsub. |
| 269 | .SH "ENVIRONMENT" |
| 270 | .IX Header "ENVIRONMENT" |
| 271 | \&\f(CW\*(C`PERL_DPROF_BUFFER\*(C'\fR sets size of output buffer in words. Defaults to 2**14. |
| 272 | .PP |
| 273 | \&\f(CW\*(C`PERL_DPROF_TICKS\*(C'\fR sets number of ticks per second on some systems where |
| 274 | a replacement for \fItimes()\fR is used. Defaults to the value of \f(CW\*(C`HZ\*(C'\fR macro. |
| 275 | .PP |
| 276 | \&\f(CW\*(C`PERL_DPROF_OUT_FILE_NAME\*(C'\fR sets the name of the output file. If not set, |
| 277 | defaults to tmon.out. |
| 278 | .SH "BUGS" |
| 279 | .IX Header "BUGS" |
| 280 | Builtin functions cannot be measured by Devel::DProf. |
| 281 | .PP |
| 282 | With a newer Perl DProf relies on the fact that the numeric slot of |
| 283 | \&\f(CW$DB::sub\fR contains an address of a subroutine. Excessive manipulation |
| 284 | of this variable may overwrite this slot, as in |
| 285 | .PP |
| 286 | .Vb 3 |
| 287 | \& $DB::sub = 'current_sub'; |
| 288 | \& ... |
| 289 | \& $addr = $DB::sub + 0; |
| 290 | .Ve |
| 291 | .PP |
| 292 | will set this numeric slot to numeric value of the string |
| 293 | \&\f(CW\*(C`current_sub\*(C'\fR, i.e., to \f(CW0\fR. This will cause a segfault on the exit |
| 294 | from this subroutine. Note that the first assignment above does not |
| 295 | change the numeric slot (it will \fImark\fR it as invalid, but will not |
| 296 | write over it). |
| 297 | .PP |
| 298 | Another problem is that if a subroutine exits using goto(\s-1LABEL\s0), |
| 299 | last(\s-1LABEL\s0) or next(\s-1LABEL\s0) then perl may crash or Devel::DProf will die |
| 300 | with the error: |
| 301 | .PP |
| 302 | .Vb 1 |
| 303 | \& panic: Devel::DProf inconsistent subroutine return |
| 304 | .Ve |
| 305 | .PP |
| 306 | For example, this code will break under Devel::DProf: |
| 307 | .PP |
| 308 | .Vb 6 |
| 309 | \& sub foo { |
| 310 | \& last FOO; |
| 311 | \& } |
| 312 | \& FOO: { |
| 313 | \& foo(); |
| 314 | \& } |
| 315 | .Ve |
| 316 | .PP |
| 317 | A pattern like this is used by Test::More's \fIskip()\fR function, for |
| 318 | example. See perldiag for more details. |
| 319 | .PP |
| 320 | Mail bug reports and feature requests to the perl5\-porters mailing list at |
| 321 | \&\fI<perl5\-porters@perl.org>\fR. |
| 322 | .SH "SEE ALSO" |
| 323 | .IX Header "SEE ALSO" |
| 324 | perl, dprofpp, \fItimes\fR\|(2) |