This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
60a93705a455d3b7db36289ab8801879b183ee20
[perl5.git] / 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