1Log::Trace::Manual(3) User Contributed Perl DocumentationLog::Trace::Manual(3)
2
6 Log::Trace::Manual - A guide to using Log::Trace
7
9 This is a brief guide to how you can use the Log::Trace module in your
10 scripts and modules. The "Log::Trace" documentation has a
11 comprehensive list of options.
12
14 You can enable tracing by specifying the tracing target via the '"use"'
15 statement or at runtime via the "import()" method. In most cases,
16 you'll want to keep the code that enables tracing in a single point,
17 usually the main script of your application. In general, modules
18 should avoid directly setting tracing options.
19 using Log::Trace in your scripts
21 Here's a slightly contrived example which demonstrates the "TRACE",
22 "TRACEF", "DUMP" and "TRACE_HERE" functions:
23 #!/usr/bin/perl -w
25 use strict;
26 use Another::Module;
27 use Log::Trace log => '/var/log/myapp.log';
28 TRACE("-------- Starting archiver ---------");
30 TRACEF("We are going to try to archive %d items", scalar @ARGV);
31 DUMP("List of things to archive", \@ARGV);
32 archive_em($_) foreach(@ARGV);
33 sub archive_em {
35 TRACE_HERE();
36 my $thing = shift;
37 unless (Another::Module::check_safe($thing)) {
38 warn "bad chars in: $thing";
39 return;
40 }
41 rename $thing, $thing.".archive" or warn "Couldn't archive $thing: $!";
42 TRACE("Tried to archive $thing");
43 }
44 Note the way "Log::Trace" is imported. The import list controls where
46 the output of the four tracing functions goes. Instead we could have
47 done:
48 use Log::Trace qw(warn);
50 and the trace output would have gone to STDERR.
52 Using Log::Trace with modules
54 In the previous example, tracing was enabled only in the main script.
55 Now we'll see how to enable tracing in "Another::Module" at the same
56 time.
57 First, "Another::Module" needs to define a "TRACE" subroutine. It may
59 also define "TRACEF", "TRACE_HERE" and "DUMP" stubs. It can do that
60 simply by using "Log::Trace". However, if "Another::Module" defines
61 its own stub tracing functions, we can remove the dependency on
62 "Log::Trace".
63 package Another::Module;
65 sub check_safe {my_routine {
67 my $filename = shift;
68 TRACE("Checking that '$filename' has safe characters");
69 return $filename =~ /^([\w.\-/]+)$/
70 }
71 sub my_other_routine {
73 TRACE_HERE();
74 }
75 # tracing stubs
77 sub TRACE {}
78 sub TRACE_HERE {}
79 Now, in the main script, we can change the '"use"' statement so tracing
81 will be enabled in "Another::Module":
82 use Log::Trace log => '/var/log/myapp.log', {Deep => 1};
84 By default, the "Deep" option will force "Log::Trace" to export tracing
86 functions to any modules that define a "TRACE" subroutine. That
87 includes modules that are not directly used by the main script. But
88 this behaviour can be relaxed or tightened with other options. See
89 "Deep import" for examples.
90 Adding "TRACE" and other stub functions to your module is an Interface
92 Contract between your module and Log::Trace (in some software circles
93 this might be given a name such as ISupportsTracing). Of course you
94 can write other code that takes advantage of this interface completely
95 independent of Log::Trace, e.g.
96 use Another::Module;
98 if($ENV{DEBUG}) {
99 *Another::Module::TRACE = sub {print "TRACE: ".join("\t",@_)."\n"};
100 }
101 Error handling
103 Since "Log::Trace" is designed with debugging in mind, all tracing
104 failures are non-fatal, so allowing normal execution to continue.
105 However, Log::Trace will report to STDERR that a problem has occurred.
106 For example, this code:
108 use Log::Trace file => '/myapp.log';
110 TRACE('Running');
111 print "Hello World!\n";
112 Will produce this output:
114 Log::Trace: Cannot open /myapp.log : Permission denied at lib/Log/Trace.pm line <nnn>.
116 Hello World!
117
119 Enabling tracing on the command line
120 You can invoke tracing on the command line:
121 perl -MLog::Trace=print -e "TRACE('hello')"
123 perl -MLog::Trace=warn -e "TRACE('hello')"
124 perl -MLog::Trace=log,test.log -e "TRACE('hello')"
125 However you can't apply this approach to scripts that use "Log::Trace"
127 or define a "TRACE" stub as these will clobber *main::TRACE set up by
128 -M when they are compiled. Fortunately it is straightforward to write
129 your command-line scripts so you can, for example, get trace output
130 with -t and deep trace output with -T:
131 use Log::Trace;
133 use Getopt::Std;
134 use MyModule;
135 use vars qw($opt_t $opt_T);
137 getopts("tT");
138 # tracing
140 import Log::Trace 'print' if $opt_t;
141 import Log::Trace 'print' => {Deep => 1} if $opt_T;
142 do_something_involving_tracing();
144 Sending TRACE output to browser in CGI
146 Whilst tracing to a log file or "STDERR" is tolerable for CGIs, it's
147 often far more convenient to return the tracing information back to the
148 browser of the client-side developer.
149 use CGI;
151 use constant DEV_SERVER => 1;
153 my $trace_buffer;
155 if(DEV_SERVER && CGI::param('Tracing')) {
156 require Log::Trace;
157 import Log::Trace buffer => \$trace_buffer, {Deep => 1};
158 }
159 my $output = do_everything();
161 print CGI::header();
163 print $output;
164 if (DEV_SERVER && $trace_buffer)
165 {
166 print "\n\n", "<pre>", CGI::escapeHTML($trace_buffer), "</pre>";
167 }
168 You should remember to change the "DEV_SERVER" constant when releasing
170 the CGI to a production environment.
171 Log levels
173 "Log::Trace" can filter the tracing output by referring to the logging
174 level. The logging level is defined when you enable tracing.
175 "Log::Trace" doesn't impose any conventions on the levels. The default
176 levels implementation requires that the levels be numeric, but that can
177 be overriden.
178 In the simplest case, you can specify the level as a threshold value:
180 use Log::Trace print => {Level => 3};
182 In this example, all trace messages at level 3 or below will be output.
184 You can also specify a list of valid levels:
186 use Log::Trace print => {Level => [0 .. 3, 7]};
188 All the tracing functions accept a hash as an optional first parameter
190 where you can specify the level for that trace message. E.g.:
191 TRACE({Level => 4}, "This is a warning");
193 TRACEF({Level => 6}, "%d items found", scalar @items);
194 TRACE_HERE({Level => 10});
195 DUMP({Level => 8}, 'Retrieved data', \%data);
196 "DUMP" is designed to accept a hash as its first parameter, but there
198 may be cases where you wish to dump a hash that contains a "Level" key.
199 In those cases, you can take advantage of the return value of "DUMP()":
200 my $dumped = DUMP({Level => 1, Health => '0.68'});
202 TRACE({Level => 8}, 'Game stats', $dumped);
203 If you specify a tracing level when you enable "Log::Trace", then
205 tracing messages that do not specify a level will not be output, unless
206 you include "undef" in the trace levels:
207 use Log::Trace print => {Level => [3, undef]};
209 TRACE("This is level undef, and will be output");
210 TRACE({Level => 3}, "This will also be output");
211 TRACE({Level => 8}, "... but this won't");
212 Here are some sample tracing levels (borrowed from Log::Agent) which
214 you can use as a guide:
215 0 emergency
217 1 alert
218 2 critical
219 3 error
220 4 warning
221 6 notice
222 8 info
223 10 debug
224 Fine-tuning deep import
226 Occasionally you won't want to see the trace output from ALL your
227 modules in your application. For example your application may give a
228 module a huge data structure or call it in a long loop. The "Exclude"
229 option allows you to mask out one or more modules.
230 use Log::Trace warn => {'Deep' => 1, 'Exclude' => 'MyVerboseModule'};
232 or
234 use Log::Trace warn => {'Deep' => 1, 'Exclude' => ['MyVerboseModule', 'Another::Module']};
236 Conversely you can use an opt-in approach rather than opt-out. The
238 "Match" option allows a regular expression to be used to select which
239 packages are initialised by Log::Trace. For example:
240 use Log::Trace print => {'Deep' => 1, 'Match' => qr/^MySubSystem::/};
242
244 Issues with the order of importing
245 When the Deep or Everywhere options are used, Log::Trace is imported
246 into all the packages which have been compiled so far.
247 use Package::Foo;
249 use Log::Trace ('print' => {Deep => 1});
250 use Package::Bar; #Compiled after Log::Trace is imported
251 In this example, the TRACE function in Package::Bar won't be
253 overridden. It's trivial to swap the order in the example above so
254 that Log::Trace is the last module used, but suppose you have a module
255 (such as a factory) that loads others on demand:
256 package MyApp::Reader;
258 sub new {
259 my $package = shift;
260 my $type = shift;
261 die unless($type =~ /^MyApp::Reader::\w+$/);
262 eval "require $type";
263 die($@) if($@);
264 return $type->new(@_);
265 }
266 How do you ensure Log::Trace gets imported into the backend
268 MyApp::Reader::* modules (without polluting all your modules with
269 Log::Trace::import calls)?
270 Using the (experimental) AutoImport feature
272 The AutoImport feature will override "CORE::require" so that from
273 now on any modules that are loaded will have the Log::Trace import
274 run against them:
275 use Log::Trace('log' => '/var/log/myapp.log', {'Deep' => 1, 'AutoImport' => 1});
277 This only works with recent versions of perl (see the ENVIRONMENT
279 NOTES in Log::Trace).
280 Getting the factory to wire the components it produces
282 A more "low-tech" approach that works with all versions of perl is
283 to get the factory to attach the stub functions of the modules it
284 loads to whatever its own stub functions have been wired to by the
285 caller.
286 package MyApp::Reader;
288 sub new {
289 my $package = shift;
290 my $type = shift;
291 die unless($type =~ /^MyApp::Reader::\w+$/);
292 eval "require $type";
293 die($@) if($@);
294 # Wire the component we've created into whatever
296 # our TRACE etc function has been wired to
297 *{"$type\::TRACE"} = \&MyApp::Reader::TRACE;
298 *{"$type\::DUMP"} = \&MyApp::Reader::DUMP;
299 return $type->new(@_);
301 }
302 Custom TRACE functions
304 If "STDOUT", "STDERR", "syslog", a file, a file handle, or a buffer is
305 not to your liking then the custom method is for you.
306 Suppose you want to send your Log::Trace output into a database:
308 our $sth;
310 $sth = setup_logging_statement();
311 use Log::Trace custom => \&log_to_database;
313 sub log_to_database {
315 #TRACE can get any number of arguments
317 my $message = join(",", @_);
318 $sth->execute($message);
320 }
322 Controlling DUMP output
324 By default, Data::Dumper is used with a fixed set of options for DUMP
325 output. You can choose a different serialiser using the "Dumper"
326 option:
327 import Log::Trace('print' => {Dumper => "YAML"}});
329 Where the string refers to a Data::Serializer::* backend. You can also
331 control the options passed to the Data::Serializer backend (and thus
332 customise the DUMP output) by passing a hashref of Data::Serializer
333 contructor options:
334 import Log::Trace('print' => {Dumper => {
336 serializer => 'XML::Dumper',
337 options => {
338 dtd => 'path/to/my.dtd'
339 }
340 }});
341 At the time of writing, not all the configuration options of the
343 underlying serialisation modules are exposed via their Data::Serializer
344 wrappers. If you find this a limitation, please contribute patches to
345 extend these modules as this will benefit a number of other modules
346 that make use of the Data::Serializer API.
347 Execution path vs. profiling
349 You can use the "AllSubs" tracing option to trace the execution path
350 through each subroutine. By default "Log::Trace" only wraps each
351 subroutine in packages with "TRACE" defined. You can force it to do it
352 to all modules using the "Everywhere" option. The following:
353 use Data::Dumper;
355 use Log::Trace print => {AllSubs => 1, Verbose => 1, Everywhere => 1, Exclude => 'Config'};
356 Data::Dumper->Dumpperl([[4]]);
357 generates the output:
359 main::__ANON__ (3) :: Data::Dumper::Dumpperl( )
361 Data::Dumper::Dumpperl (3) :: Data::Dumper::new( )
362 Data::Dumper::Dumpperl (3) :: Data::Dumper::_dump( Data::Dumper, ... )
363 Data::Dumper::_dump (205) :: overload::StrVal( ARRAY, ... )
364 overload::StrVal (239) :: overload::OverloadedStringify( ARRAY, ... )
365 overload::OverloadedStringify (92) :: overload::mycan( )
366 overload::OverloadedStringify (92) :: overload::ov_method( )
367 overload::OverloadedStringify (92) :: overload::mycan( )
368 overload::OverloadedStringify (92) :: overload::ov_method( )
369 overload::OverloadedStringify (92) :: overload::mycan( )
370 overload::OverloadedStringify (92) :: overload::ov_method( )
371 overload::OverloadedStringify (92) :: overload::mycan( )
372 overload::OverloadedStringify (92) :: overload::ov_method( )
373 Data::Dumper::_dump (205) :: Data::Dumper::_dump( Data::Dumper, ... )
374 (eval) (0) :: Data::Dumper::DESTROY( Data::Dumper, ... )
375 Targeting one module
377 You may wonder "How do I trace what's going on in module Acme::Foo I
378 downloaded from CPAN that isn't Log::Trace enabled?". Assuming the
379 module doesn't have any other kind of tracing that you can hook into,
380 all you can do is use the "AllSubs" approach. Assuming that's OK, you
381 can restrict this to just the offending module with:
382 use Log::Trace print => {AllSubs => 1, Everywhere => 1, Match => qr/^Acme:Foo$/};
384 Avoiding performance penalty
386 Although the trace stubs don't do anything, they do incur a small
387 function call overhead. If this performance hit is unacceptable, you
388 can use a constant to enable/disable all the "Log::Trace" statements in
389 your code. The test for the constant value will be optimised out at
390 compile time so no runtime overhead is incurred if the constant has a
391 false value:
392 package ThrashMe;
394 use constant TRACING_ENABLED => 1; #Set to zero to optimise
396 sub performance_critical {
398 TRACE("this may slow things down") if(TRACING_ENABLED);
399 do_stuff();
400 }
401 sub TRACE{}
403 1;
405
407 $Revision: 1.9 $
408perl v5.32.0 2020-07-28 Log::Trace::Manual(3)