This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
Document and test the phase-change probe
[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 =back
59
60 =head1 PROBES
61
62 =over 4
63
64 =item sub-entry(SUBNAME, FILE, LINE, PACKAGE)
65
66 Traces the entry of any subroutine. Note that all of the variables
67 refer to the subroutine that is being invoked; there is currently
68 no way to get ahold of any information about the subroutine's
69 I<caller> from a DTrace action.
70
71     :*perl*::sub-entry {
72         printf("%s::%s entered at %s line %d\n",
73                copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
74     }
75
76 =item sub-return(SUBNAME, FILE, LINE, PACKAGE)
77
78 Traces the exit of any subroutine. Note that all of the variables
79 refer to the subroutine that is returning; there is currently no
80 way to get ahold of any information about the subroutine's I<caller>
81 from a DTrace action.
82
83     :*perl*::sub-return {
84         printf("%s::%s returned at %s line %d\n",
85                copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
86     }
87
88 =item phase-change(NEWPHASE, OLDPHASE)
89
90 Traces changes to Perl's interpreter state. You can internalize this
91 as tracing changes to Perl's C<${^GLOBAL_PHASE}> variable, especially
92 since the values for C<NEWPHASE> and C<OLDPHASE> are the strings that
93 C<${^GLOBAL_PHASE}> reports.
94
95     :*perl*::phase-change {
96         printf("Phase changed from %s to %s\n",
97             copyinstr(arg1), copyinstr(arg0));
98     }
99
100 =back
101
102 =head1 EXAMPLES
103
104 =over 4
105
106 =item Most frequently called functions
107
108     # dtrace -qZn 'sub-entry { @[strjoin(strjoin(copyinstr(arg3),"::"),copyinstr(arg0))] = count() } END {trunc(@, 10)}'
109
110     Class::MOP::Attribute::slots                                    400
111     Try::Tiny::catch                                                411
112     Try::Tiny::try                                                  411
113     Class::MOP::Instance::inline_slot_access                        451
114     Class::MOP::Class::Immutable::Trait:::around                    472
115     Class::MOP::Mixin::AttributeCore::has_initializer               496
116     Class::MOP::Method::Wrapped::__ANON__                           544
117     Class::MOP::Package::_package_stash                             737
118     Class::MOP::Class::initialize                                  1128
119     Class::MOP::get_metaclass_by_name                              1204
120
121 =item Trace function calls
122
123     # dtrace -qFZn 'sub-entry, sub-return { trace(copyinstr(arg0)) }'
124
125     0  -> Perl_pp_entersub                        BEGIN
126     0  <- Perl_pp_leavesub                        BEGIN
127     0  -> Perl_pp_entersub                        BEGIN
128     0    -> Perl_pp_entersub                      import
129     0    <- Perl_pp_leavesub                      import
130     0  <- Perl_pp_leavesub                        BEGIN
131     0  -> Perl_pp_entersub                        BEGIN
132     0    -> Perl_pp_entersub                      dress
133     0    <- Perl_pp_leavesub                      dress
134     0    -> Perl_pp_entersub                      dirty
135     0    <- Perl_pp_leavesub                      dirty
136     0    -> Perl_pp_entersub                      whiten
137     0    <- Perl_pp_leavesub                      whiten
138     0  <- Perl_dounwind                           BEGIN
139
140 =item Function calls during interpreter cleanup
141
142     # dtrace -Zn 'phase-change /copyinstr(arg0) == "END"/ { self->ending = 1 } sub-entry /self->ending/ { trace(copyinstr(arg0)) }'
143
144     CPU     ID                    FUNCTION:NAME
145       1  77214       Perl_pp_entersub:sub-entry   END
146       1  77214       Perl_pp_entersub:sub-entry   END
147       1  77214       Perl_pp_entersub:sub-entry   cleanup
148       1  77214       Perl_pp_entersub:sub-entry   _force_writable
149       1  77214       Perl_pp_entersub:sub-entry   _force_writable
150
151 =item System calls at compile time
152
153     # 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) }'
154
155     lseek                                                           310
156     read                                                            374
157     stat64                                                         1056
158
159 =back
160
161 =head1 REFERENCES
162
163 =over 4
164
165 =item DTrace User Guide
166
167 L<http://download.oracle.com/docs/cd/E19082-01/819-3620/index.html>
168
169 =item DTrace: Dynamic Tracing in Oracle Solaris, Mac OS X and FreeBSD
170
171 L<http://www.amazon.com/DTrace-Dynamic-Tracing-Solaris-FreeBSD/dp/0132091518/>
172
173 =back
174
175 =head1 AUTHORS
176
177 Shawn M Moore C<sartak@gmail.com>
178
179 =cut