[perl5.git] / pod / perldtrace.pod

=head1 NAME

perldtrace - Perl's support for DTrace

=head1 SYNOPSIS

    # dtrace -Zn 'perl::sub-entry, perl::sub-return { trace(copyinstr(arg0)) }'
    dtrace: description 'perl::sub-entry, perl::sub-return ' matched 10 probes

    # perl -E 'sub outer { inner(@_) } sub inner { say shift } outer("hello")'
    hello

    (dtrace output)
    CPU     ID                    FUNCTION:NAME
      0  75915       Perl_pp_entersub:sub-entry   BEGIN
      0  75915       Perl_pp_entersub:sub-entry   import
      0  75922      Perl_pp_leavesub:sub-return   import
      0  75922      Perl_pp_leavesub:sub-return   BEGIN
      0  75915       Perl_pp_entersub:sub-entry   outer
      0  75915       Perl_pp_entersub:sub-entry   inner
      0  75922      Perl_pp_leavesub:sub-return   inner
      0  75922      Perl_pp_leavesub:sub-return   outer

=head1 DESCRIPTION

DTrace is a framework for comprehensive system- and application-level
tracing. Perl is a DTrace I<provider>, meaning it exposes several
I<probes> for instrumentation. You can use these in conjunction
with kernel-level probes, as well as probes from other providers
such as MySQL, in order to diagnose software defects, or even just
your application's bottlenecks.

Perl must be compiled with the C<-Dusedtrace> option in order to
make use of the provided probes. While DTrace aims to have no
overhead when its instrumentation is not active, Perl's support
itself cannot uphold that guarantee, so it is built without DTrace
probes under most systems. One notable exception is that Mac OS X
ships a F</usr/bin/perl> with DTrace support enabled.

=head1 HISTORY

=over 4

=item 5.10.1

Perl's initial DTrace support was added, providing C<sub-entry> and
C<sub-return> probes.

=item 5.14.0

The C<sub-entry> and C<sub-return> probes gain a fourth argument: the
package name of the function.

=item 5.16.0

The C<phase-change> probe was added.

=back

=head1 PROBES

=over 4

=item sub-entry(SUBNAME, FILE, LINE, PACKAGE)

Traces the entry of any subroutine. Note that all of the variables
refer to the subroutine that is being invoked; there is currently
no way to get ahold of any information about the subroutine's
I<caller> from a DTrace action.

    :*perl*::sub-entry {
        printf("%s::%s entered at %s line %d\n",
               copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
    }

=item sub-return(SUBNAME, FILE, LINE, PACKAGE)

Traces the exit of any subroutine. Note that all of the variables
refer to the subroutine that is returning; there is currently no
way to get ahold of any information about the subroutine's I<caller>
from a DTrace action.

    :*perl*::sub-return {
        printf("%s::%s returned at %s line %d\n",
               copyinstr(arg3), copyinstr(arg0), copyinstr(arg1), arg0);
    }

=item phase-change(NEWPHASE, OLDPHASE)

Traces changes to Perl's interpreter state. You can internalize this
as tracing changes to Perl's C<${^GLOBAL_PHASE}> variable, especially
since the values for C<NEWPHASE> and C<OLDPHASE> are the strings that
C<${^GLOBAL_PHASE}> reports.

    :*perl*::phase-change {
        printf("Phase changed from %s to %s\n",
            copyinstr(arg1), copyinstr(arg0));
    }

=back

=head1 EXAMPLES

=over 4

=item Most frequently called functions

    # dtrace -qZn 'sub-entry { @[strjoin(strjoin(copyinstr(arg3),"::"),copyinstr(arg0))] = count() } END {trunc(@, 10)}'

    Class::MOP::Attribute::slots                                    400
    Try::Tiny::catch                                                411
    Try::Tiny::try                                                  411
    Class::MOP::Instance::inline_slot_access                        451
    Class::MOP::Class::Immutable::Trait:::around                    472
    Class::MOP::Mixin::AttributeCore::has_initializer               496
    Class::MOP::Method::Wrapped::__ANON__                           544
    Class::MOP::Package::_package_stash                             737
    Class::MOP::Class::initialize                                  1128
    Class::MOP::get_metaclass_by_name                              1204

=item Trace function calls

    # dtrace -qFZn 'sub-entry, sub-return { trace(copyinstr(arg0)) }'

    0  -> Perl_pp_entersub                        BEGIN
    0  <- Perl_pp_leavesub                        BEGIN
    0  -> Perl_pp_entersub                        BEGIN
    0    -> Perl_pp_entersub                      import
    0    <- Perl_pp_leavesub                      import
    0  <- Perl_pp_leavesub                        BEGIN
    0  -> Perl_pp_entersub                        BEGIN
    0    -> Perl_pp_entersub                      dress
    0    <- Perl_pp_leavesub                      dress
    0    -> Perl_pp_entersub                      dirty
    0    <- Perl_pp_leavesub                      dirty
    0    -> Perl_pp_entersub                      whiten
    0    <- Perl_pp_leavesub                      whiten
    0  <- Perl_dounwind                           BEGIN

=item Function calls during interpreter cleanup

    # dtrace -Zn 'phase-change /copyinstr(arg0) == "END"/ { self->ending = 1 } sub-entry /self->ending/ { trace(copyinstr(arg0)) }'

    CPU     ID                    FUNCTION:NAME
      1  77214       Perl_pp_entersub:sub-entry   END
      1  77214       Perl_pp_entersub:sub-entry   END
      1  77214       Perl_pp_entersub:sub-entry   cleanup
      1  77214       Perl_pp_entersub:sub-entry   _force_writable
      1  77214       Perl_pp_entersub:sub-entry   _force_writable

=item System calls at compile time

    # 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) }'

    lseek                                                           310
    read                                                            374
    stat64                                                         1056

=back

=head1 REFERENCES

=over 4

=item DTrace User Guide

L<http://download.oracle.com/docs/cd/E19082-01/819-3620/index.html>

=item DTrace: Dynamic Tracing in Oracle Solaris, Mac OS X and FreeBSD

L<http://www.amazon.com/DTrace-Dynamic-Tracing-Solaris-FreeBSD/dp/0132091518/>

=back

=head1 AUTHORS

Shawn M Moore C<sartak@gmail.com>

=cut
Commit	Line	Data
f993ad5b SM	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
2b679393 SM	54	=item 5.16.0
	55
	56	The C<phase-change> probe was added.
	57
f993ad5b SM	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
2b679393 SM	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
f993ad5b SM	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
2b679393 SM	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
f993ad5b SM	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