Hack 82. Trace Your Ops


Watch Perl execute individual instructions.

Unlike so-called natively compiled programs, Perl programs are instructions for the Perl virtual machine. When Perl compiles a program, it reduces it to a tree of opcodes, such as "fetch this lexical variable" and "add the attached constant." If you want to see what your program is doing, the best[18] way is to examine each individual opcode.

[18] Though not necessarily the easiest.

The B::* modulesthe compiler backend to Perlgive you some flexibility in examining compiled code from Perl. They don't give you many opportunities to play with ops as Perl runs them, however. Fortunately, Runops::Trace does.

The Hack

Runops::Trace replaces Perl's standard runloop with an alternate runloop that calls back to Perl code, passing the B::* object representing the next op that will run. This allows you to request and log any data from that op.

Perl's standard runloop executes the current op, fetches the next op after that, dispatches any signals that have arrived, and repeats.


For example, to count the number of accesses to global symbols within a program, write a callback logger:

package TraceGlobals; use strict; use warnings; use Runops::Trace \\&trace_globals; my %globals; sub trace_globals {     return unless $_[0]->isa( 'B::SVOP' ) && $_[0]->name( ) eq 'gv';     my $gv   = shift->gv( );     my $data = $globals{ $gv->SAFENAME( ) } ||= { };     my $key  = $gv->FILE( ) . ':' . $gv->LINE( );     $data->{$key}++; } END {     Runops::Trace->unimport( );     for my $gv ( sort keys %globals )     {         my $gv_data = $globals{ $gv };         my @counts  = keys %$gv_data;         for my $line ( sort { $gv_data->{$b} <=> $gv_data->{$a} } @counts)         {             printf "%04d %s %-> s\\n", $gv_data->{$line}, $gv, $line;         }     } } 1;

The important work is in trace_globals( ). The subroutine first examines its only argument, throwing out all non-SV opcodes and all non-GV opcodes. (These are opcodes that access typeglobs, or GVs, as the Perl internals call them.) Then it fetches the GV object attached to the op, logging the name of the GV (SAFENAME( )) and the file (FILE( )) and line (LINE( )) where the symbol occurs.

The END block formats and reports this data nicely. The call to Runops::Trace->unimport( ) at the start prevents the tracing module from accidentally trying to trace itself at the end of the program.

Running the Hack

Because of the way Runops::Trace installs its tracing runloop, you must load a tracing module before the code you want to trace. The easiest way to do this is from the command line, perhaps on the program from "Find All Symbols in a Package" [Hack #75]:

$ perl -MTraceGlobals find_package_symbols.pl Foo:find_package_symbols.pl:14         ($foo, $bar, $baz) Bar:find_package_symbols.pl:18 Foo:find_package_symbols.pl:14         ($foo, $bar, $baz) Data::Dumper:/usr/lib/perl5/site_perl/5.8.7/powerpc-linux/Data/Dumper.pm:484 0001 AddrRef -> /usr/lib/perl5/5.8.7/overload.pm:94 0054 Bits -> /usr/lib/perl5/5.8.7/warnings.pm:189 0003 Cache -> /usr/lib/perl5/5.8.7/Exporter.pm:13 0002 DeadBits -> /usr/lib/perl5/5.8.7/warnings.pm:239 0001 Dumper -> /usr/lib/perl5/5.8.7/Exporter.pm:65 0001 EXPORT -> /usr/lib/perl5/site_perl/5.8.7/powerpc-linux/Data/Dumper.pm:24 0001 EXPORT_OK -> /usr/lib/perl5/site_perl/5.8.7/powerpc-linux/         Data/Dumper.pm:25 0001 ISA -> /usr/lib/perl5/site_perl/5.8.7/powerpc-linux/Data/Dumper.pm:23 0002 Offsets -> /usr/lib/perl5/5.8.7/warnings.pm:136 0003 SIG -> /usr/lib/perl5/5.8.7/Exporter.pm:62 0001 StrVal -> /usr/lib/perl5/site_perl/5.8.7/powerpc-linux/         Data/Dumper.pm:104 0037 _ -> :0 <...>

The first part of the output is the normal program output, as the program runs as normal. The second half of the output shows the number of accesses, the name of the symbol, and the file and line of the definition of the symbol. The final line is interestingit shows the requests made for the glob named _, usually accessed as @_ and not defined in a package or a file.

Hacking the Hack

Finding all of the global symbols is interesting, especially if you want to explore a certain code path where static analysis isn't helpful [Hack #77]. You can do much, much more with a tracing runloop. Consider that the callback function is basically the entry point into an event-driven state machine. Find the type of ops you want to query and perform your behavior based on that.

For example, to measure the amount of time you spend in one package over another, look for the B::COP objects that represent the nextstate op and keep timing information. To see when a variable changes, look for B::SVOP objects accessing that particular variable.

A future enhancement to Runops::Trace may allow you to change the next op, declining to handle dangerous or indelicate operations, or even redirecting to different ops. To learn more, read the documentation for B and become familiar with optrees with B::Concise and B::Terse.



Perl Hacks
Perl Hacks: Tips & Tools for Programming, Debugging, and Surviving
ISBN: 0596526741
EAN: 2147483647
Year: 2004
Pages: 141

flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net