#!/usr/bin/perl -w use strict; use Another::Module; use Log::Trace log => '/var/log/myapp.log'; TRACE("-------- Starting archiver ---------"); TRACEF("We are going to try to archive %d items", scalar @ARGV); DUMP("List of things to archive", \@ARGV); archive_em($_) foreach(@ARGV); sub archive_em { TRACE_HERE(); my $thing = shift; unless (Another::Module::check_safe($thing)) { warn "bad chars in: $thing"; return; } rename $thing, $thing.".archive" or warn "Couldn't archive $thing: $!"; TRACE("Tried to archive $thing"); }
Note the way "Log::Trace" is imported. The import list controls where the output of the four tracing functions goes. Instead we could have done:
use Log::Trace qw(warn);
and the trace output would have gone to STDERR.
First, "Another::Module" needs to define a "TRACE" subroutine. It may also define "TRACEF", "TRACE_HERE" and "DUMP" stubs. It can do that simply by using "Log::Trace". However, if "Another::Module" defines its own stub tracing functions, we can remove the dependency on "Log::Trace".
package Another::Module; sub check_safe {my_routine { my $filename = shift; TRACE("Checking that '$filename' has safe characters"); return $filename =~ /^([\w.\-/]+)$/ } sub my_other_routine { TRACE_HERE(); } # tracing stubs sub TRACE {} sub TRACE_HERE {}
Now, in the main script, we can change the '"use"' statement so tracing will be enabled in "Another::Module":
use Log::Trace log => '/var/log/myapp.log', {Deep => 1};
By default, the "Deep" option will force "Log::Trace" to export tracing functions to any modules that define a "TRACE" subroutine. That includes modules that are not directly used by the main script. But this behaviour can be relaxed or tightened with other options. See ``Deep import'' for examples.
Adding "TRACE" and other stub functions to your module is an Interface Contract between your module and Log::Trace (in some software circles this might be given a name such as ISupportsTracing). Of course you can write other code that takes advantage of this interface completely independent of Log::Trace, e.g.
use Another::Module; if($ENV{DEBUG}) { *Another::Module::TRACE = sub {print "TRACE: ".join("\t",@_)."\n"}; }
For example, this code:
use Log::Trace file => '/myapp.log'; TRACE('Running'); print "Hello World!\n";
Will produce this output:
Log::Trace: Cannot open /myapp.log : Permission denied at lib/Log/Trace.pm line <nnn>. Hello World!
perl -MLog::Trace=print -e "TRACE('hello')" perl -MLog::Trace=warn -e "TRACE('hello')" perl -MLog::Trace=log,test.log -e "TRACE('hello')"
However you can't apply this approach to scripts that use "Log::Trace" or define a "TRACE" stub as these will clobber *main::TRACE set up by -M when they are compiled. Fortunately it is straightforward to write your command-line scripts so you can, for example, get trace output with -t and deep trace output with -T:
use Log::Trace; use Getopt::Std; use MyModule; use vars qw($opt_t $opt_T); getopts("tT"); # tracing import Log::Trace 'print' if $opt_t; import Log::Trace 'print' => {Deep => 1} if $opt_T; do_something_involving_tracing();
use CGI; use constant DEV_SERVER => 1; my $trace_buffer; if(DEV_SERVER && CGI::param('Tracing')) { require Log::Trace; import Log::Trace buffer => \$trace_buffer, {Deep => 1}; } my $output = do_everything(); print CGI::header(); print $output; if (DEV_SERVER && $trace_buffer) { print "\n\n", "<pre>", CGI::escapeHTML($trace_buffer), "</pre>"; }
You should remember to change the "DEV_SERVER" constant when releasing the CGI to a production environment.
In the simplest case, you can specify the level as a threshold value:
use Log::Trace print => {Level => 3};
In this example, all trace messages at level 3 or below will be output.
You can also specify a list of valid levels:
use Log::Trace print => {Level => [0 .. 3, 7]};
All the tracing functions accept a hash as an optional first parameter where you can specify the level for that trace message. E.g.:
TRACE({Level => 4}, "This is a warning"); TRACEF({Level => 6}, "%d items found", scalar @items); TRACE_HERE({Level => 10}); DUMP({Level => 8}, 'Retrieved data', \%data);
"DUMP" is designed to accept a hash as its first parameter, but there may be cases where you wish to dump a hash that contains a "Level" key. In those cases, you can take advantage of the return value of "DUMP()":
my $dumped = DUMP({Level => 1, Health => '0.68'}); TRACE({Level => 8}, 'Game stats', $dumped);
If you specify a tracing level when you enable "Log::Trace", then tracing messages that do not specify a level will not be output, unless you include "undef" in the trace levels:
use Log::Trace print => {Level => [3, undef]}; TRACE("This is level undef, and will be output"); TRACE({Level => 3}, "This will also be output"); TRACE({Level => 8}, "... but this won't");
Here are some sample tracing levels (borrowed from Log::Agent) which you can use as a guide:
0 emergency 1 alert 2 critical 3 error 4 warning 6 notice 8 info 10 debug
use Log::Trace warn => {'Deep' => 1, 'Exclude' => 'MyVerboseModule'};
or
use Log::Trace warn => {'Deep' => 1, 'Exclude' => ['MyVerboseModule', 'Another::Module']};
Conversely you can use an opt-in approach rather than opt-out. The "Match" option allows a regular expression to be used to select which packages are initialised by Log::Trace. For example:
use Log::Trace print => {'Deep' => 1, 'Match' => qr/^MySubSystem::/};
use Package::Foo; use Log::Trace ('print' => {Deep => 1}); use Package::Bar; #Compiled after Log::Trace is imported
In this example, the TRACE function in Package::Bar won't be overridden. It's trivial to swap the order in the example above so that Log::Trace is the last module used, but suppose you have a module (such as a factory) that loads others on demand:
package MyApp::Reader; sub new { my $package = shift; my $type = shift; die unless($type =~ /^MyApp::Reader::\w+$/); eval "require $type"; die($@) if($@); return $type->new(@_); }
How do you ensure Log::Trace gets imported into the backend MyApp::Reader::* modules (without polluting all your modules with Log::Trace::import calls)?
use Log::Trace('log' => '/var/log/myapp.log', {'Deep' => 1, 'AutoImport' => 1});
This only works with recent versions of perl (see the ENVIRONMENT NOTES in Log::Trace).
package MyApp::Reader; sub new { my $package = shift; my $type = shift; die unless($type =~ /^MyApp::Reader::\w+$/); eval "require $type"; die($@) if($@); # Wire the component we've created into whatever # our TRACE etc function has been wired to *{"$type\::TRACE"} = \&MyApp::Reader::TRACE; *{"$type\::DUMP"} = \&MyApp::Reader::DUMP; return $type->new(@_); }
Suppose you want to send your Log::Trace output into a database:
our $sth; $sth = setup_logging_statement(); use Log::Trace custom => \&log_to_database; sub log_to_database { #TRACE can get any number of arguments my $message = join(",", @_); $sth->execute($message); }
import Log::Trace('print' => {Dumper => "YAML"}});
Where the string refers to a Data::Serializer::* backend. You can also control the options passed to the Data::Serializer backend (and thus customise the DUMP output) by passing a hashref of Data::Serializer contructor options:
import Log::Trace('print' => {Dumper => { serializer => 'XML::Dumper', options => { dtd => 'path/to/my.dtd' } }});
At the time of writing, not all the configuration options of the underlying serialisation modules are exposed via their Data::Serializer wrappers. If you find this a limitation, please contribute patches to extend these modules as this will benefit a number of other modules that make use of the Data::Serializer API.
use Data::Dumper; use Log::Trace print => {AllSubs => 1, Verbose => 1, Everywhere => 1, Exclude => 'Config'}; Data::Dumper->Dumpperl([[4]]);
generates the output:
main::__ANON__ (3) :: Data::Dumper::Dumpperl( ) Data::Dumper::Dumpperl (3) :: Data::Dumper::new( ) Data::Dumper::Dumpperl (3) :: Data::Dumper::_dump( Data::Dumper, ... ) Data::Dumper::_dump (205) :: overload::StrVal( ARRAY, ... ) overload::StrVal (239) :: overload::OverloadedStringify( ARRAY, ... ) overload::OverloadedStringify (92) :: overload::mycan( ) overload::OverloadedStringify (92) :: overload::ov_method( ) overload::OverloadedStringify (92) :: overload::mycan( ) overload::OverloadedStringify (92) :: overload::ov_method( ) overload::OverloadedStringify (92) :: overload::mycan( ) overload::OverloadedStringify (92) :: overload::ov_method( ) overload::OverloadedStringify (92) :: overload::mycan( ) overload::OverloadedStringify (92) :: overload::ov_method( ) Data::Dumper::_dump (205) :: Data::Dumper::_dump( Data::Dumper, ... ) (eval) (0) :: Data::Dumper::DESTROY( Data::Dumper, ... )
use Log::Trace print => {AllSubs => 1, Everywhere => 1, Match => qr/^Acme:Foo$/};
package ThrashMe; use constant TRACING_ENABLED => 1; #Set to zero to optimise sub performance_critical { TRACE("this may slow things down") if(TRACING_ENABLED); do_stuff(); } sub TRACE{} 1;