ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/AnyEvent/lib/AnyEvent/Log.pm
(Generate patch)

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.10 by root, Fri Aug 19 21:17:08 2011 UTC vs.
Revision 1.11 by root, Sat Aug 20 01:03:09 2011 UTC

45AnyEvent - AnyEvent simply creates logging messages internally, and this 45AnyEvent - AnyEvent simply creates logging messages internally, and this
46module more or less exposes the mechanism, with some extra spiff to allow 46module more or less exposes the mechanism, with some extra spiff to allow
47using it from other modules as well. 47using it from other modules as well.
48 48
49Remember that the default verbosity level is C<0>, so nothing will be 49Remember that the default verbosity level is C<0>, so nothing will be
50logged, ever, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number 50logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number before
51before starting your program, or change the logging level at runtime wiht 51starting your program, or change the logging level at runtime with
52something like: 52something like:
53 53
54 use AnyEvent; 54 use AnyEvent;
55 (AnyEvent::Log::ctx "")->level ("info"); 55 (AnyEvent::Log::ctx "")->level ("info");
56 56
96# creates a default package context object for the given package 96# creates a default package context object for the given package
97sub _pkg_ctx($) { 97sub _pkg_ctx($) {
98 my $ctx = bless [$_[0], (1 << 10) - 1 - 1, {}], "AnyEvent::Log::Ctx"; 98 my $ctx = bless [$_[0], (1 << 10) - 1 - 1, {}], "AnyEvent::Log::Ctx";
99 99
100 # link "parent" package 100 # link "parent" package
101 my $pkg = $_[0] =~ /^(.+)::/ ? $1 : ""; 101 my $pkg = $_[0] =~ /^(.+)::/ ? $1 : "AE::Log::Top";
102 102
103 $pkg = $CTX{$pkg} ||= &_pkg_ctx ($pkg); 103 $pkg = $CTX{$pkg} ||= &_pkg_ctx ($pkg);
104 $ctx->[2]{$pkg+0} = $pkg; 104 $ctx->[2]{$pkg+0} = $pkg;
105 105
106 $ctx 106 $ctx
132Note that you can (and should) call this function as C<AnyEvent::log> or 132Note that you can (and should) call this function as C<AnyEvent::log> or
133C<AE::log>, without C<use>-ing this module if possible (i.e. you don't 133C<AE::log>, without C<use>-ing this module if possible (i.e. you don't
134need any additional functionality), as those functions will load the 134need any additional functionality), as those functions will load the
135logging module on demand only. They are also much shorter to write. 135logging module on demand only. They are also much shorter to write.
136 136
137Also, if you otpionally generate a lot of debug messages (such as when 137Also, if you optionally generate a lot of debug messages (such as when
138tracing some code), you should look into using a logger callback and a 138tracing some code), you should look into using a logger callback and a
139boolean enabler (see C<logger>, below). 139boolean enabler (see C<logger>, below).
140 140
141Example: log something at error level. 141Example: log something at error level.
142 142
173 173
174our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); 174our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
175 175
176# time, ctx, level, msg 176# time, ctx, level, msg
177sub _format($$$$) { 177sub _format($$$$) {
178 my $pfx = ft $_[0]; 178 my $ts = ft $_[0];
179 my $ct = " ";
180
179 my @res; 181 my @res;
180 182
181 for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) { 183 for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) {
182 push @res, "$pfx $_\n"; 184 push @res, "$ts$ct$_\n";
183 $pfx = "\t"; 185 $ct = " + ";
184 } 186 }
185 187
186 join "", @res 188 join "", @res
187} 189}
188 190
189sub _log { 191sub _log {
190 my ($ctx, $level, $format, @args) = @_; 192 my ($ctx, $level, $format, @args) = @_;
191 193
194 $level = $level > 0 && $level <= 9
195 ? $level+0
192 $level = $level > 0 && $level <= 9 ? $level+0 : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught"; 196 : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught";
193 197
194 my $mask = 1 << $level; 198 my $mask = 1 << $level;
195 199
196 my (@ctx, $now, $fmt); 200 my (%seen, @ctx, $now, $fmt);
197 201
198 do { 202 do
203 {
199 # skip if masked 204 # skip if masked
200 next unless $ctx->[1] & $mask; 205 if ($ctx->[1] & $mask && !$seen{$ctx+0}++) {
201
202 if ($ctx->[3]) { 206 if ($ctx->[3]) {
203 # logging target found 207 # logging target found
204 208
205 # now get raw message, unless we have it already 209 # now get raw message, unless we have it already
206 unless ($now) { 210 unless ($now) {
207 $format = $format->() if ref $format; 211 $format = $format->() if ref $format;
208 $format = sprintf $format, @args if @args; 212 $format = sprintf $format, @args if @args;
209 $format =~ s/\n$//; 213 $format =~ s/\n$//;
210 $now = AE::now; 214 $now = AE::now;
211 }; 215 };
212 216
213 # format msg 217 # format msg
214 my $str = $ctx->[4] 218 my $str = $ctx->[4]
215 ? $ctx->[4]($now, $_[0], $level, $format) 219 ? $ctx->[4]($now, $_[0], $level, $format)
216 : $fmt ||= _format $now, $_[0], $level, $format; 220 : $fmt ||= _format $now, $_[0], $level, $format;
217 221
218 $ctx->[3]($str) 222 $ctx->[3]($str);
219 and next; 223 }
224
225 # not masked, not consumed - propagate to parent contexts
226 push @ctx, values %{ $ctx->[2] };
227 }
220 } 228 }
221
222 # not masked, not consume - propagate to parent contexts
223 push @ctx, values %{ $ctx->[2] };
224 } while $ctx = pop @ctx; 229 while $ctx = pop @ctx;
225 230
226 exit 1 if $level <= 1; 231 exit 1 if $level <= 1;
227} 232}
228 233
229sub log($$;@) { 234sub log($$;@) {
282# re-assess logging status for all loggers 287# re-assess logging status for all loggers
283sub _reassess { 288sub _reassess {
284 for (@_ ? $LOGGER{$_[0]} : values %LOGGER) { 289 for (@_ ? $LOGGER{$_[0]} : values %LOGGER) {
285 my ($ctx, $level, $renabled) = @$_; 290 my ($ctx, $level, $renabled) = @$_;
286 291
287 # to detetc whether a message would be logged, we # actually 292 # to detect whether a message would be logged, we # actually
288 # try to log one and die. this isn't # fast, but we can be 293 # try to log one and die. this isn't fast, but we can be
289 # sure that the logging decision is correct :) 294 # sure that the logging decision is correct :)
290 295
291 $$renabled = !eval { 296 $$renabled = !eval {
292 local $SIG{__DIE__}; 297 local $SIG{__DIE__};
293 298
356For propagation, a context can have any number of attached I<parent 361For propagation, a context can have any number of attached I<parent
357contexts>. Any message that is neither masked by the logging mask nor 362contexts>. Any message that is neither masked by the logging mask nor
358masked by the logging callback returning true will be passed to all parent 363masked by the logging callback returning true will be passed to all parent
359contexts. 364contexts.
360 365
366Each call to a logging function will log the message at most once per
367context, so it does not matter (much) if there are cycles or if the
368message can arrive at the same context via multiple paths.
369
361=head2 DEFAULTS 370=head2 DEFAULTS
362 371
363By default, all logging contexts have an full set of log levels ("all"), a 372By default, all logging contexts have an full set of log levels ("all"), a
364disabled logging callback and the default formatting callback. 373disabled logging callback and the default formatting callback.
365 374
366Package contexts have the package name as logging title by default. 375Package contexts have the package name as logging title by default.
367 376
368They have exactly one parent - the context of the "parent" package. The 377They have exactly one parent - the context of the "parent" package. The
369parent package is simply defined to be the package name without the last 378parent package is simply defined to be the package name without the last
370component, i.e. C<AnyEvent::Debug::Wrapped> becomes C<AnyEvent::Debug>, 379component, i.e. C<AnyEvent::Debug::Wrapped> becomes C<AnyEvent::Debug>,
371and C<AnyEvent> becomes the empty string. 380and C<AnyEvent> becomes ... C<AnyEvent::Log::Top> which is the
381exception of the rule - just like the parent of any package name in
382Perl is C<main>, the default parent of any toplevel package context is
383C<AnyEvent::Log::Top>.
372 384
373Since perl packages form only an approximate hierarchy, this parent 385Since perl packages form only an approximate hierarchy, this parent
374context can of course be removed. 386context can of course be removed.
375 387
376All other (anonymous) contexts have no parents and an empty title by 388All other (anonymous) contexts have no parents and an empty title by
377default. 389default.
378 390
379When the module is first loaded, it configures the root context (the one 391When the module is loaded it creates the default context called
380with the empty string) to simply dump all log messages to C<STDERR>, 392C<AnyEvent::Log::Default>, which simply logs everything to STDERR and
393doesn't propagate anything anywhere by default. The purpose of the default
394context is to provide a convenient place to override the global logging
395target or to attach additional log targets. It's not meant for filtering.
396
397It then creates the root context called C<AnyEvent::Log::Root> and
381and sets it's log level set to all levels up to the one specified by 398sets its log level set to all levels up to the one specified by
382C<$ENV{PERL_ANYEVENT_VERBOSE}>. 399C<$ENV{PERL_ANYEVENT_VERBOSE}>. It then attached the default logging
400context to it. The purpose of the root context is to simply provide
401filtering according to some global log level.
383 402
403Finally it creates the toplevel package context called
404C<AnyEvent::Log::Top> and attached the root context but otherwise leaves
405it at default config. It's purpose is simply to collect all log messages
406system-wide.
407
408These three special contexts can also be referred to by the names
409C<AE::Log::Default>, C<AE::Log::Root> and C<AE::Log::Top>.
410
384The effect of all this is that log messages, by default, wander up to the 411The effect of all this is that log messages, by default, wander up
385root context and will be logged to STDERR if their log level is less than 412to the root context where log messages with lower priority then
386or equal to C<$ENV{PERL_ANYEVENT_VERBOSE}>. 413C<$ENV{PERL_ANYEVENT_VERBOSE}> will be filtered away and then to the
414AnyEvent::Log::Default context to be logged to STDERR.
387 415
416Splitting the top level context into three contexts makes it easy to set
417a global logging level (by modifying the root context), but still allow
418other contexts to log, for example, their debug and trace messages to the
419default target despite the global logging level, or to attach additional
420log targets that log messages, regardless of the global logging level.
421
422It also makes it easy to replace the default STDERR-logger by something
423that logs to a file, or to attach additional logging targets.
424
388=head2 CREATING/FINDING A CONTEXT 425=head2 CREATING/FINDING/DESTROYING CONTEXTS
389 426
390=over 4 427=over 4
391 428
392=item $ctx = AnyEvent::Log::ctx [$pkg] 429=item $ctx = AnyEvent::Log::ctx [$pkg]
393 430
411 : defined $pkg 448 : defined $pkg
412 ? $CTX{$pkg} ||= AnyEvent::Log::_pkg_ctx $pkg 449 ? $CTX{$pkg} ||= AnyEvent::Log::_pkg_ctx $pkg
413 : bless [undef, (1 << 10) - 1 - 1], "AnyEvent::Log::Ctx" 450 : bless [undef, (1 << 10) - 1 - 1], "AnyEvent::Log::Ctx"
414} 451}
415 452
416# create default root context 453=item AnyEvent::Log::reset
417{ 454
455Deletes all contexts and recreates the default hierarchy, i.e. resets the
456logging subsystem to defaults.
457
458This can be used to implement config-file (re-)loading: before loading a
459configuration, reset all contexts.
460
461=cut
462
463sub reset {
464 @$_ = () for values %CTX; # just to be sure - to kill circular logging dependencies
465 %CTX = ();
466
418 my $root = ctx undef; 467 my $default = ctx undef;
419 $root->[0] = ""; 468 $default->title ("AnyEvent::Log::Default");
420 $root->title ("default");
421 $root->level ($AnyEvent::VERBOSE); undef $AnyEvent::VERBOSE;
422 $root->log_cb (sub { 469 $default->log_cb (sub {
423 print STDERR shift; 470 print STDERR shift;
424 0 471 0
425 }); 472 });
426 $CTX{""} = $root; 473 $CTX{"AnyEvent::Log::Default"} = $CTX{"AE::Log::Default"} = $default;
474
475 my $root = ctx undef;
476 $root->title ("AnyEvent::Log::Root");
477 $root->level ($AnyEvent::VERBOSE);
478 $root->attach ($default);
479 $CTX{"AnyEvent::Log::Root"} = $CTX{"AE::Log::Root"} = $root;
480
481 my $top = ctx undef;
482 $top->title ("AnyEvent::Log::Top");
483 $top->attach ($root);
484 $CTX{"AnyEvent::Log::Top"} = $CTX{"AE::Log::Top"} = $top;
427} 485}
486
487AnyEvent::Log::reset;
488
489package AnyEvent::Log::Default;
490package AE::Log::Default;
491package AnyEvent::Log::Root;
492package AE::Log::Root;
493package AnyEvent::Log::Top;
494package AE::Log::Top;
428 495
429=back 496=back
430 497
431=cut 498=cut
432 499
559Removes the given parents from this context - it's not an error to attempt 626Removes the given parents from this context - it's not an error to attempt
560to remove a context that hasn't been added. 627to remove a context that hasn't been added.
561 628
562A context can be specified either as package name or as a context object. 629A context can be specified either as package name or as a context object.
563 630
631=item $ctx->parents ($ctx2[, $ctx3...])
632
633Replaces all parents attached to this context by the ones given.
634
564=cut 635=cut
565 636
566sub attach { 637sub attach {
567 my $ctx = shift; 638 my $ctx = shift;
568 639
573sub detach { 644sub detach {
574 my $ctx = shift; 645 my $ctx = shift;
575 646
576 delete $ctx->[2]{$_+0} 647 delete $ctx->[2]{$_+0}
577 for map { AnyEvent::Log::ctx $_ } @_; 648 for map { AnyEvent::Log::ctx $_ } @_;
649}
650
651sub parents {
652 undef $_[0][2];
653 &attach;
578} 654}
579 655
580=back 656=back
581 657
582=head3 MESSAGE LOGGING 658=head3 MESSAGE LOGGING

Diff Legend

Removed lines
+ Added lines
< Changed lines
> Changed lines