pod/perldtrace.pod

   1 =head1 NAME
   2
   3 perldtrace - Perl's support for DTrace
   4
   5 =head1 SYNOPSIS
   6
   7     # dtrace -Zn 'perl::sub-entry, perl::sub-return { trace(copyinstr(arg0)) }'
   8     dtrace: description 'perl::sub-entry, perl::sub-return ' matched 10 probes
   9
  10     # perl -E 'sub outer { inner(@_) } sub inner { say shift } outer("hello")'
  11     hello
  12
  13     (dtrace output)
  14     CPU     ID                    FUNCTION:NAME
  15       0  75915       Perl_pp_entersub:sub-entry   BEGIN
  16       0  75915       Perl_pp_entersub:sub-entry   import
  17       0  75922      Perl_pp_leavesub:sub-return   import
  18       0  75922      Perl_pp_leavesub:sub-return   BEGIN
  19       0  75915       Perl_pp_entersub:sub-entry   outer
  20       0  75915       Perl_pp_entersub:sub-entry   inner
  21       0  75922      Perl_pp_leavesub:sub-return   inner
  22       0  75922      Perl_pp_leavesub:sub-return   outer
  23
  24 =head1 DESCRIPTION
  25
  26 DTrace is a framework for comprehensive system- and application-level
  27 tracing. Perl is a DTrace I<provider>, meaning it exposes several
  28 I<probes> for instrumentation. You can use these in conjunction
  29 with kernel-level probes, as well as probes from other providers
  30 such as MySQL, in order to diagnose software defects, or even just
  31 your application's bottlenecks.
  32
  33 Perl must be compiled with the C<-Dusedtrace> option in order to
  34 make use of the provided probes. While DTrace aims to have no
  35 overhead when its instrumentation is not active, Perl's support
  36 itself cannot uphold that guarantee, so it is built without DTrace
  37 probes under most systems. One notable exception is that Mac OS X
  38 ships a F</usr/bin/perl> with DTrace support enabled.
  39
  40 =head1 HISTORY
  41
  42 =over 4
  43
  44 =item 5.10.1
  45
  46 Perl's initial DTrace support was added, providing C<sub-entry> and
  47 C<sub-return> probes.
  48
  49 =item 5.14.0
  50
  51 The C<sub-entry> and C<sub-return> probes gain a fourth argument: the
  52 package name of the function.
  53
  54 =item 5.16.0
  55
  56 The C<phase-change> probe was added.
  57
  58 =item 5.18.0
  59
  60 The C<op-entry> probe was added.
  61
  62 =back
  63
  64 =head1 PROBES
  65
  66 =over 4
  67
  68 =item sub-entry(SUBNAME, FILE, LINE, PACKAGE)
  69
  70 Traces the entry of any subroutine. Note that all of the variables
  71 refer to the subroutine that is being invoked; there is currently
  72 no way to get ahold of any information about the subroutine's
  73 I<caller> from a DTrace action.
  74
  75     :*perl*::sub-entry {
  76         printf("%s::%s entered at %s line %d\n",
  77                copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
  78     }
  79
  80 =item sub-return(SUBNAME, FILE, LINE, PACKAGE)
  81
  82 Traces the exit of any subroutine. Note that all of the variables
  83 refer to the subroutine that is returning; there is currently no
  84 way to get ahold of any information about the subroutine's I<caller>
  85 from a DTrace action.
  86
  87     :*perl*::sub-return {
  88         printf("%s::%s returned at %s line %d\n",
  89                copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
  90     }
  91
  92 =item phase-change(NEWPHASE, OLDPHASE)
  93
  94 Traces changes to Perl's interpreter state. You can internalize this
  95 as tracing changes to Perl's C<${^GLOBAL_PHASE}> variable, especially
  96 since the values for C<NEWPHASE> and C<OLDPHASE> are the strings that
  97 C<${^GLOBAL_PHASE}> reports.
  98
  99     :*perl*::phase-change {
 100         printf("Phase changed from %s to %s\n",
 101             copyinstr(arg1), copyinstr(arg0));
 102     }
 103
 104 =item op-entry(OPNAME)
 105
 106 Traces the execution of each opcode in the Perl runloop. This probe
 107 is fired before the opcode is executed. When the Perl debugger is
 108 enabled, the DTrace probe is fired I<after> the debugger hooks (but
 109 still before the opcode itself is executed).
 110
 111     :*perl*::op-entry {
 112         printf("About to execute opcode %s\n", copyinstr(arg0));
 113     }
 114
 115 =back
 116
 117 =head1 EXAMPLES
 118
 119 =over 4
 120
 121 =item Most frequently called functions
 122
 123     # dtrace -qZn 'sub-entry { @[strjoin(strjoin(copyinstr(arg3),"::"),copyinstr(arg0))] = count() } END {trunc(@, 10)}'
 124
 125     Class::MOP::Attribute::slots                                    400
 126     Try::Tiny::catch                                                411
 127     Try::Tiny::try                                                  411
 128     Class::MOP::Instance::inline_slot_access                        451
 129     Class::MOP::Class::Immutable::Trait:::around                    472
 130     Class::MOP::Mixin::AttributeCore::has_initializer               496
 131     Class::MOP::Method::Wrapped::__ANON__                           544
 132     Class::MOP::Package::_package_stash                             737
 133     Class::MOP::Class::initialize                                  1128
 134     Class::MOP::get_metaclass_by_name                              1204
 135
 136 =item Trace function calls
 137
 138     # dtrace -qFZn 'sub-entry, sub-return { trace(copyinstr(arg0)) }'
 139
 140     0  -> Perl_pp_entersub                        BEGIN
 141     0  <- Perl_pp_leavesub                        BEGIN
 142     0  -> Perl_pp_entersub                        BEGIN
 143     0    -> Perl_pp_entersub                      import
 144     0    <- Perl_pp_leavesub                      import
 145     0  <- Perl_pp_leavesub                        BEGIN
 146     0  -> Perl_pp_entersub                        BEGIN
 147     0    -> Perl_pp_entersub                      dress
 148     0    <- Perl_pp_leavesub                      dress
 149     0    -> Perl_pp_entersub                      dirty
 150     0    <- Perl_pp_leavesub                      dirty
 151     0    -> Perl_pp_entersub                      whiten
 152     0    <- Perl_pp_leavesub                      whiten
 153     0  <- Perl_dounwind                           BEGIN
 154
 155 =item Function calls during interpreter cleanup
 156
 157     # dtrace -Zn 'phase-change /copyinstr(arg0) == "END"/ { self->ending = 1 } sub-entry /self->ending/ { trace(copyinstr(arg0)) }'
 158
 159     CPU     ID                    FUNCTION:NAME
 160       1  77214       Perl_pp_entersub:sub-entry   END
 161       1  77214       Perl_pp_entersub:sub-entry   END
 162       1  77214       Perl_pp_entersub:sub-entry   cleanup
 163       1  77214       Perl_pp_entersub:sub-entry   _force_writable
 164       1  77214       Perl_pp_entersub:sub-entry   _force_writable
 165
 166 =item System calls at compile time
 167
 168     # dtrace -qZn 'phase-change /copyinstr(arg0) == "START"/ { self->interesting = 1 } phase-change /copyinstr(arg0) == "RUN"/ { self->interesting = 0 } syscall::: /self->interesting/ { @[probefunc] = count() } END { trunc(@, 3) }'
 169
 170     lseek                                                           310
 171     read                                                            374
 172     stat64                                                         1056
 173
 174 =item Perl functions that execute the most opcodes
 175
 176     # dtrace -qZn 'sub-entry { self->fqn = strjoin(copyinstr(arg3), strjoin("::", copyinstr(arg0))) } op-entry /self->fqn != ""/ { @[self->fqn] = count() } END { trunc(@, 3) }'
 177
 178     warnings::unimport                                             4589
 179     Exporter::Heavy::_rebuild_cache                                5039
 180     Exporter::import                                              14578
 181
 182 =back
 183
 184 =head1 REFERENCES
 185
 186 =over 4
 187
 188 =item DTrace User Guide
 189
 190 L<http://download.oracle.com/docs/cd/E19082-01/819-3620/index.html>
 191
 192 =item DTrace: Dynamic Tracing in Oracle Solaris, Mac OS X and FreeBSD
 193
 194 L<http://www.amazon.com/DTrace-Dynamic-Tracing-Solaris-FreeBSD/dp/0132091518/>
 195
 196 =back
 197
 198 =head1 SEE ALSO
 199
 200 =over 4
 201
 202 =item L<Devel::DTrace::Provider>
 203
 204 This CPAN module lets you create application-level DTrace probes written in Perl.
 205
 206 =back
 207
 208 =head1 AUTHORS
 209
 210 Shawn M Moore C<sartak@gmail.com>
 211
 212 =cut