Document and test the phase-change probe
authorShawn M Moore <sartak@gmail.com>
Tue, 12 Jul 2011 12:49:10 +0000 (08:49 -0400)
committerFather Chrysostomos <sprout@cpan.org>
Tue, 12 Jul 2011 14:08:16 +0000 (07:08 -0700)
pod/perldelta.pod
pod/perldtrace.pod
t/run/dtrace.t

index 6306189..b91d66c 100644 (file)
@@ -53,6 +53,14 @@ exhaust memory).
 New in Unicode 6.0, this is an improved C<Script> property.  Details
 are in L<perlunicode/Scripts>.
 
+=head2 DTrace probes for interpreter phase change
+
+The C<phase-change> probes will fire when the interpreter's phase
+changes, which tracks the C<${^GLOBAL_PHASE}> variable. C<arg0> is
+the new phase name; C<arg1> is the old one. This is useful mostly
+for limiting your instrumentation to one or more of: compile time,
+run time, destruct time.
+
 =head1 Security
 
 XXX Any security-related notices go here.  In particular, any security
@@ -278,9 +286,10 @@ file and be sure to link to the appropriate page, e.g. L<perlfunc>.
 
 XXX Changes which create B<new> files in F<pod/> go here.
 
-=head3 L<XXX>
+=head3 L<perldtrace>
 
-XXX Description of the purpose of the new file here
+L<perldtrace> describes Perl's DTrace support, listing the provided probes
+and gives examples of their use.
 
 =head2 Changes to Existing Documentation
 
@@ -401,7 +410,11 @@ that they represent may be covered elsewhere.
 
 =item *
 
-XXX
+F<t/run/dtrace.t> was added to test Perl's DTrace support. This
+test will only be run if your Perl was built with C<-Dusedtrace>
+and if calling C<dtrace> actually lets you instrument code. This
+generally requires being run as root, so this test file is primarily
+intended for use by the dtrace subcommittee of p5p.
 
 =back
 
index 2654417..39551e1 100644 (file)
@@ -51,6 +51,10 @@ C<sub-return> probes.
 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
@@ -81,6 +85,18 @@ from a DTrace action.
                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
@@ -106,20 +122,39 @@ from a DTrace action.
 
     # 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 
+    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
 
index 4ea851e..625e403 100644 (file)
@@ -24,7 +24,7 @@ use strict;
 use warnings;
 use IPC::Open2;
 
-plan(tests => 2);
+plan(tests => 5);
 
 dtrace_like(
     '1',
@@ -55,6 +55,68 @@ dtrace_like(
     'traced multiple function calls',
 );
 
+dtrace_like(
+    '1',
+    'phase-change { printf("%s -> %s; ", copyinstr(arg1), copyinstr(arg0)) }',
+    qr/START -> RUN; RUN -> DESTRUCT;/,
+    'phase changes of a simple script',
+);
+
+# this code taken from t/op/magic_phase.t which tests all of the
+# transitions of ${^GLOBAL_PHASE}. instead of printing (which will
+# interact nondeterministically with the DTrace output), we increment
+# an unused variable for side effects
+dtrace_like(<< 'MAGIC_OP',
+    my $x = 0;
+    BEGIN { $x++ }
+    CHECK { $x++ }
+    INIT  { $x++ }
+    sub Moo::DESTROY { $x++ }
+
+    my $tiger = bless {}, Moo::;
+
+    sub Kooh::DESTROY { $x++ }
+
+    our $affe = bless {}, Kooh::;
+
+    END { $x++ }
+MAGIC_OP
+
+    'phase-change { printf("%s -> %s; ", copyinstr(arg1), copyinstr(arg0)) }',
+
+     qr/START -> CHECK; CHECK -> INIT; INIT -> RUN; RUN -> END; END -> DESTRUCT;/,
+
+     'phase-changes in a script that exercises all of ${^GLOBAL_PHASE}',
+);
+
+dtrace_like(<< 'PHASES',
+    my $x = 0;
+    sub foo { $x++ }
+    sub bar { $x++ }
+    sub baz { $x++ }
+
+    INIT { foo() }
+    bar();
+    END { baz() }
+PHASES
+
+    '
+    BEGIN { starting = 1 }
+
+    phase-change                            { phase    = arg0 }
+    phase-change /copyinstr(arg0) == "RUN"/ { starting = 0 }
+    phase-change /copyinstr(arg0) == "END"/ { ending   = 1 }
+
+    sub-entry /copyinstr(arg0) != copyinstr(phase) && (starting || ending)/ {
+        printf("%s during %s; ", copyinstr(arg0), copyinstr(phase));
+    }
+    ',
+
+     qr/foo during INIT; baz during END;/,
+
+     'make sure sub-entry and phase-change interact well',
+);
+
 sub dtrace_like {
     my $perl     = shift;
     my $probes   = shift;