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