ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/AnyEvent/lib/AnyEvent/Log.pm
Revision: 1.27
Committed: Wed Aug 24 23:59:10 2011 UTC (12 years, 9 months ago) by root
Branch: MAIN
Changes since 1.26: +218 -6 lines
Log Message:
*** empty log message ***

File Contents

# Content
1 =head1 NAME
2
3 AnyEvent::Log - simple logging "framework"
4
5 =head1 SYNOPSIS
6
7 Simple uses:
8
9 use AnyEvent;
10
11 AE::log debug => "hit my knee";
12 AE::log warn => "it's a bit too hot";
13 AE::log error => "the flag was false!";
14 AE::log fatal => "the bit toggled! run!"; # never returns
15
16 "Complex" uses (for speed sensitive code):
17
18 use AnyEvent::Log;
19
20 my $tracer = AnyEvent::Log::logger trace => \$my $trace;
21
22 $tracer->("i am here") if $trace;
23 $tracer->(sub { "lots of data: " . Dumper $self }) if $trace;
24
25 Configuration (also look at the EXAMPLES section):
26
27 # set logging for the current package to errors and higher only
28 AnyEvent::Log::ctx->level ("error");
29
30 # set logging level to suppress anything below "notice"
31 $AnyEvent::Log::FILTER->level ("notice");
32
33 # send all critical and higher priority messages to syslog,
34 # regardless of (most) other settings
35 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
36 level => "critical",
37 log_to_syslog => 0,
38 );
39
40 =head1 DESCRIPTION
41
42 This module implements a relatively simple "logging framework". It doesn't
43 attempt to be "the" logging solution or even "a" logging solution for
44 AnyEvent - AnyEvent simply creates logging messages internally, and this
45 module more or less exposes the mechanism, with some extra spiff to allow
46 using it from other modules as well.
47
48 Remember that the default verbosity level is C<0> (C<off>), so nothing
49 will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number
50 before starting your program, or change the logging level at runtime with
51 something like:
52
53 use AnyEvent::Log;
54 AnyEvent::Log::FILTER->level ("info");
55
56 The design goal behind this module was to keep it simple (and small),
57 but make it powerful enough to be potentially useful for any module, and
58 extensive enough for the most common tasks, such as logging to multiple
59 targets, or being able to log into a database.
60
61 The amount of documentation might indicate otherwise, but the module is
62 still just below 300 lines of code.
63
64 =head1 LOGGING LEVELS
65
66 Logging levels in this module range from C<1> (highest priority) to C<9>
67 (lowest priority). Note that the lowest numerical value is the highest
68 priority, so when this document says "higher priority" it means "lower
69 numerical value".
70
71 Instead of specifying levels by name you can also specify them by aliases:
72
73 LVL NAME SYSLOG PERL NOTE
74 1 fatal emerg exit aborts program!
75 2 alert
76 3 critical crit
77 4 error err die
78 5 warn warning
79 6 note notice
80 7 info
81 8 debug
82 9 trace
83
84 As you can see, some logging levels have multiple aliases - the first one
85 is the "official" name, the second one the "syslog" name (if it differs)
86 and the third one the "perl" name, suggesting that you log C<die> messages
87 at C<error> priority.
88
89 You can normally only log a single message at highest priority level
90 (C<1>, C<fatal>), because logging a fatal message will also quit the
91 program - so use it sparingly :)
92
93 Some methods also offer some extra levels, such as C<0>, C<off>, C<none>
94 or C<all> - these are only valid in the methods they are documented for.
95
96 =head1 LOGGING FUNCTIONS
97
98 These functions allow you to log messages. They always use the caller's
99 package as a "logging context". Also, the main logging function C<log> is
100 callable as C<AnyEvent::log> or C<AE::log> when the C<AnyEvent> module is
101 loaded.
102
103 =over 4
104
105 =cut
106
107 package AnyEvent::Log;
108
109 use Carp ();
110 use POSIX ();
111
112 use AnyEvent (); BEGIN { AnyEvent::common_sense }
113 use AnyEvent::Util ();
114
115 our $VERSION = $AnyEvent::VERSION;
116
117 our ($COLLECT, $FILTER, $LOG);
118
119 our ($now_int, $now_str1, $now_str2);
120
121 # Format Time, not public - yet?
122 sub ft($) {
123 my $i = int $_[0];
124 my $f = sprintf "%06d", 1e6 * ($_[0] - $i);
125
126 ($now_int, $now_str1, $now_str2) = ($i, split /\x01/, POSIX::strftime "%Y-%m-%d %H:%M:%S.\x01 %z", localtime $i)
127 if $now_int != $i;
128
129 "$now_str1$f$now_str2"
130 }
131
132 our %CTX; # all package contexts
133
134 # creates a default package context object for the given package
135 sub _pkg_ctx($) {
136 my $ctx = bless [$_[0], (1 << 10) - 1 - 1, {}], "AnyEvent::Log::Ctx";
137
138 # link "parent" package
139 my $parent = $_[0] =~ /^(.+)::/
140 ? $CTX{$1} ||= &_pkg_ctx ("$1")
141 : $COLLECT;
142
143 $ctx->[2]{$parent+0} = $parent;
144
145 $ctx
146 }
147
148 =item AnyEvent::Log::log $level, $msg[, @args]
149
150 Requests logging of the given C<$msg> with the given log level, and
151 returns true if the message was logged I<somewhere>.
152
153 For C<fatal> log levels, the program will abort.
154
155 If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the
156 C<$msg> is interpreted as an sprintf format string.
157
158 The C<$msg> should not end with C<\n>, but may if that is convenient for
159 you. Also, multiline messages are handled properly.
160
161 Last not least, C<$msg> might be a code reference, in which case it is
162 supposed to return the message. It will be called only then the message
163 actually gets logged, which is useful if it is costly to create the
164 message in the first place.
165
166 Whether the given message will be logged depends on the maximum log level
167 and the caller's package. The return value can be used to ensure that
168 messages or not "lost" - for example, when L<AnyEvent::Debug> detects a
169 runtime error it tries to log it at C<die> level, but if that message is
170 lost it simply uses warn.
171
172 Note that you can (and should) call this function as C<AnyEvent::log> or
173 C<AE::log>, without C<use>-ing this module if possible (i.e. you don't
174 need any additional functionality), as those functions will load the
175 logging module on demand only. They are also much shorter to write.
176
177 Also, if you optionally generate a lot of debug messages (such as when
178 tracing some code), you should look into using a logger callback and a
179 boolean enabler (see C<logger>, below).
180
181 Example: log something at error level.
182
183 AE::log error => "something";
184
185 Example: use printf-formatting.
186
187 AE::log info => "%5d %-10.10s %s", $index, $category, $msg;
188
189 Example: only generate a costly dump when the message is actually being logged.
190
191 AE::log debug => sub { require Data::Dump; Data::Dump::dump \%cache };
192
193 =cut
194
195 # also allow syslog equivalent names
196 our %STR2LEVEL = (
197 fatal => 1, emerg => 1, exit => 1,
198 alert => 2,
199 critical => 3, crit => 3,
200 error => 4, err => 4, die => 4,
201 warn => 5, warning => 5,
202 note => 6, notice => 6,
203 info => 7,
204 debug => 8,
205 trace => 9,
206 );
207
208 sub now () { time }
209
210 AnyEvent::post_detect {
211 *now = \&AE::now;
212 };
213
214 our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
215
216 # time, ctx, level, msg
217 sub _format($$$$) {
218 my $ts = ft $_[0];
219 my $ct = " ";
220
221 my @res;
222
223 for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) {
224 push @res, "$ts$ct$_\n";
225 $ct = " + ";
226 }
227
228 join "", @res
229 }
230
231 sub _log {
232 my ($ctx, $level, $format, @args) = @_;
233
234 $level = $level > 0 && $level <= 9
235 ? $level+0
236 : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught";
237
238 my $mask = 1 << $level;
239
240 my ($success, %seen, @ctx, $now, $fmt);
241
242 do
243 {
244 # skip if masked
245 if ($ctx->[1] & $mask && !$seen{$ctx+0}++) {
246 if ($ctx->[3]) {
247 # logging target found
248
249 # now get raw message, unless we have it already
250 unless ($now) {
251 $format = $format->() if ref $format;
252 $format = sprintf $format, @args if @args;
253 $format =~ s/\n$//;
254 $now = AE::now;
255 };
256
257 # format msg
258 my $str = $ctx->[4]
259 ? $ctx->[4]($now, $_[0], $level, $format)
260 : ($fmt ||= _format $now, $_[0], $level, $format);
261
262 $success = 1;
263
264 $ctx->[3]($str)
265 or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate
266 } else {
267 push @ctx, values %{ $ctx->[2] }; # not masked - propagate
268 }
269 }
270 }
271 while $ctx = pop @ctx;
272
273 exit 1 if $level <= 1;
274
275 $success
276 }
277
278 sub log($$;@) {
279 _log
280 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
281 @_;
282 }
283
284 *AnyEvent::log = *AE::log = \&log;
285
286 =item $logger = AnyEvent::Log::logger $level[, \$enabled]
287
288 Creates a code reference that, when called, acts as if the
289 C<AnyEvent::Log::log> function was called at this point with the given
290 level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with
291 the C<AnyEvent::Log::log> function:
292
293 my $debug_log = AnyEvent::Log::logger "debug";
294
295 $debug_log->("debug here");
296 $debug_log->("%06d emails processed", 12345);
297 $debug_log->(sub { $obj->as_string });
298
299 The idea behind this function is to decide whether to log before actually
300 logging - when the C<logger> function is called once, but the returned
301 logger callback often, then this can be a tremendous speed win.
302
303 Despite this speed advantage, changes in logging configuration will
304 still be reflected by the logger callback, even if configuration changes
305 I<after> it was created.
306
307 To further speed up logging, you can bind a scalar variable to the logger,
308 which contains true if the logger should be called or not - if it is
309 false, calling the logger can be safely skipped. This variable will be
310 updated as long as C<$logger> is alive.
311
312 Full example:
313
314 # near the init section
315 use AnyEvent::Log;
316
317 my $debug_log = AnyEvent:Log::logger debug => \my $debug;
318
319 # and later in your program
320 $debug_log->("yo, stuff here") if $debug;
321
322 $debug and $debug_log->("123");
323
324 =cut
325
326 our %LOGGER;
327
328 # re-assess logging status for all loggers
329 sub _reassess {
330 local $SIG{__DIE__};
331 my $die = sub { die };
332
333 for (@_ ? $LOGGER{$_[0]} : values %LOGGER) {
334 my ($ctx, $level, $renabled) = @$_;
335
336 # to detect whether a message would be logged, we actually
337 # try to log one and die. this isn't fast, but we can be
338 # sure that the logging decision is correct :)
339
340 $$renabled = !eval {
341 _log $ctx, $level, $die;
342
343 1
344 };
345 }
346 }
347
348 sub _logger {
349 my ($ctx, $level, $renabled) = @_;
350
351 $$renabled = 1;
352
353 my $logger = [$ctx, $level, $renabled];
354
355 $LOGGER{$logger+0} = $logger;
356
357 _reassess $logger+0;
358
359 my $guard = AnyEvent::Util::guard {
360 # "clean up"
361 delete $LOGGER{$logger+0};
362 };
363
364 sub {
365 $guard if 0; # keep guard alive, but don't cause runtime overhead
366
367 _log $ctx, $level, @_
368 if $$renabled;
369 }
370 }
371
372 sub logger($;$) {
373 _logger
374 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
375 @_
376 }
377
378 =back
379
380 =head1 LOGGING CONTEXTS
381
382 This module associates every log message with a so-called I<logging
383 context>, based on the package of the caller. Every perl package has its
384 own logging context.
385
386 A logging context has three major responsibilities: filtering, logging and
387 propagating the message.
388
389 For the first purpose, filtering, each context has a set of logging
390 levels, called the log level mask. Messages not in the set will be ignored
391 by this context (masked).
392
393 For logging, the context stores a formatting callback (which takes the
394 timestamp, context, level and string message and formats it in the way
395 it should be logged) and a logging callback (which is responsible for
396 actually logging the formatted message and telling C<AnyEvent::Log>
397 whether it has consumed the message, or whether it should be propagated).
398
399 For propagation, a context can have any number of attached I<slave
400 contexts>. Any message that is neither masked by the logging mask nor
401 masked by the logging callback returning true will be passed to all slave
402 contexts.
403
404 Each call to a logging function will log the message at most once per
405 context, so it does not matter (much) if there are cycles or if the
406 message can arrive at the same context via multiple paths.
407
408 =head2 DEFAULTS
409
410 By default, all logging contexts have an full set of log levels ("all"), a
411 disabled logging callback and the default formatting callback.
412
413 Package contexts have the package name as logging title by default.
414
415 They have exactly one slave - the context of the "parent" package. The
416 parent package is simply defined to be the package name without the last
417 component, i.e. C<AnyEvent::Debug::Wrapped> becomes C<AnyEvent::Debug>,
418 and C<AnyEvent> becomes ... C<$AnyEvent::Log::COLLECT> which is the
419 exception of the rule - just like the "parent" of any single-component
420 package name in Perl is C<main>, the default slave of any top-level
421 package context is C<$AnyEvent::Log::COLLECT>.
422
423 Since perl packages form only an approximate hierarchy, this slave
424 context can of course be removed.
425
426 All other (anonymous) contexts have no slaves and an empty title by
427 default.
428
429 When the module is loaded it creates the C<$AnyEvent::Log::LOG> logging
430 context that simply logs everything via C<warn>, without propagating
431 anything anywhere by default. The purpose of this context is to provide
432 a convenient place to override the global logging target or to attach
433 additional log targets. It's not meant for filtering.
434
435 It then creates the C<$AnyEvent::Log::FILTER> context whose
436 purpose is to suppress all messages with priority higher
437 than C<$ENV{PERL_ANYEVENT_VERBOSE}>. It then attached the
438 C<$AnyEvent::Log::LOG> context to it. The purpose of the filter context
439 is to simply provide filtering according to some global log level.
440
441 Finally it creates the top-level package context C<$AnyEvent::Log::COLLECT>
442 and attaches the C<$AnyEvent::Log::FILTER> context to it, but otherwise
443 leaves it at default config. Its purpose is simply to collect all log
444 messages system-wide.
445
446 The hierarchy is then:
447
448 any package, eventually -> $COLLECT -> $FILTER -> $LOG
449
450 The effect of all this is that log messages, by default, wander up to the
451 C<$AnyEvent::Log::COLLECT> context where all messages normally end up,
452 from there to C<$AnyEvent::Log::FILTER> where log messages with lower
453 priority then C<$ENV{PERL_ANYEVENT_VERBOSE}> will be filtered out and then
454 to the C<$AnyEvent::Log::LOG> context to be passed to C<warn>.
455
456 This makes it easy to set a global logging level (by modifying $FILTER),
457 but still allow other contexts to send, for example, their debug and trace
458 messages to the $LOG target despite the global logging level, or to attach
459 additional log targets that log messages, regardless of the global logging
460 level.
461
462 It also makes it easy to modify the default warn-logger ($LOG) to
463 something that logs to a file, or to attach additional logging targets
464 (such as loggign to a file) by attaching it to $FILTER.
465
466 =head2 CREATING/FINDING/DESTROYING CONTEXTS
467
468 =over 4
469
470 =item $ctx = AnyEvent::Log::ctx [$pkg]
471
472 This function creates or returns a logging context (which is an object).
473
474 If a package name is given, then the context for that packlage is
475 returned. If it is called without any arguments, then the context for the
476 callers package is returned (i.e. the same context as a C<AE::log> call
477 would use).
478
479 If C<undef> is given, then it creates a new anonymous context that is not
480 tied to any package and is destroyed when no longer referenced.
481
482 =cut
483
484 sub ctx(;$) {
485 my $pkg = @_ ? shift : (caller)[0];
486
487 ref $pkg
488 ? $pkg
489 : defined $pkg
490 ? $CTX{$pkg} ||= AnyEvent::Log::_pkg_ctx $pkg
491 : bless [undef, (1 << 10) - 1 - 1], "AnyEvent::Log::Ctx"
492 }
493
494 =item AnyEvent::Log::reset
495
496 Resets all package contexts and recreates the default hierarchy if
497 necessary, i.e. resets the logging subsystem to defaults, as much as
498 possible. This process keeps references to contexts held by other parts of
499 the program intact.
500
501 This can be used to implement config-file (re-)loading: before loading a
502 configuration, reset all contexts.
503
504 =cut
505
506 sub reset {
507 # hard to kill complex data structures
508 # we "recreate" all package loggers and reset the hierarchy
509 while (my ($k, $v) = each %CTX) {
510 @$v = ($k, (1 << 10) - 1 - 1, { });
511
512 $v->attach ($k =~ /^(.+)::/ ? $CTX{$1} : $AnyEvent::Log::COLLECT);
513 }
514
515 @$_ = ($_->[0], (1 << 10) - 1 - 1)
516 for $LOG, $FILTER, $COLLECT;
517
518 $LOG->slaves;
519 $LOG->title ('$AnyEvent::Log::LOG');
520 $LOG->log_to_warn;
521
522 $FILTER->slaves ($LOG);
523 $FILTER->title ('$AnyEvent::Log::FILTER');
524 $FILTER->level ($AnyEvent::VERBOSE);
525
526 $COLLECT->slaves ($FILTER);
527 $COLLECT->title ('$AnyEvent::Log::COLLECT');
528
529 _reassess;
530 }
531
532 # create the default logger contexts
533 $LOG = ctx undef;
534 $FILTER = ctx undef;
535 $COLLECT = ctx undef;
536
537 AnyEvent::Log::reset;
538
539 # hello, CPAN, please catch me
540 package AnyEvent::Log::LOG;
541 package AE::Log::LOG;
542 package AnyEvent::Log::FILTER;
543 package AE::Log::FILTER;
544 package AnyEvent::Log::COLLECT;
545 package AE::Log::COLLECT;
546
547 package AnyEvent::Log::Ctx;
548
549 # 0 1 2 3 4
550 # [$title, $level, %$slaves, &$logcb, &$fmtcb]
551
552 =item $ctx = new AnyEvent::Log::Ctx methodname => param...
553
554 This is a convenience constructor that makes it simpler to construct
555 anonymous logging contexts.
556
557 Each key-value pair results in an invocation of the method of the same
558 name as the key with the value as parameter, unless the value is an
559 arrayref, in which case it calls the method with the contents of the
560 array. The methods are called in the same order as specified.
561
562 Example: create a new logging context and set both the default logging
563 level, some slave contexts and a logging callback.
564
565 $ctx = new AnyEvent::Log::Ctx
566 title => "dubious messages",
567 level => "error",
568 log_cb => sub { print STDOUT shift; 0 },
569 slaves => [$ctx1, $ctx, $ctx2],
570 ;
571
572 =back
573
574 =cut
575
576 sub new {
577 my $class = shift;
578
579 my $ctx = AnyEvent::Log::ctx undef;
580
581 while (@_) {
582 my ($k, $v) = splice @_, 0, 2;
583 $ctx->$k (ref $v eq "ARRAY" ? @$v : $v);
584 }
585
586 bless $ctx, $class # do we really support subclassing, hmm?
587 }
588
589
590 =head2 CONFIGURING A LOG CONTEXT
591
592 The following methods can be used to configure the logging context.
593
594 =over 4
595
596 =item $ctx->title ([$new_title])
597
598 Returns the title of the logging context - this is the package name, for
599 package contexts, and a user defined string for all others.
600
601 If C<$new_title> is given, then it replaces the package name or title.
602
603 =cut
604
605 sub title {
606 $_[0][0] = $_[1] if @_ > 1;
607 $_[0][0]
608 }
609
610 =back
611
612 =head3 LOGGING LEVELS
613
614 The following methods deal with the logging level set associated with the
615 log context.
616
617 The most common method to use is probably C<< $ctx->level ($level) >>,
618 which configures the specified and any higher priority levels.
619
620 All functions which accept a list of levels also accept the special string
621 C<all> which expands to all logging levels.
622
623 =over 4
624
625 =item $ctx->levels ($level[, $level...)
626
627 Enables logging for the given levels and disables it for all others.
628
629 =item $ctx->level ($level)
630
631 Enables logging for the given level and all lower level (higher priority)
632 ones. In addition to normal logging levels, specifying a level of C<0> or
633 C<off> disables all logging for this level.
634
635 Example: log warnings, errors and higher priority messages.
636
637 $ctx->level ("warn");
638 $ctx->level (5); # same thing, just numeric
639
640 =item $ctx->enable ($level[, $level...])
641
642 Enables logging for the given levels, leaving all others unchanged.
643
644 =item $ctx->disable ($level[, $level...])
645
646 Disables logging for the given levels, leaving all others unchanged.
647
648 =cut
649
650 sub _lvl_lst {
651 map {
652 $_ > 0 && $_ <= 9 ? $_+0
653 : $_ eq "all" ? (1 .. 9)
654 : $STR2LEVEL{$_} || Carp::croak "$_: not a valid logging level, caught"
655 } @_
656 }
657
658 our $NOP_CB = sub { 0 };
659
660 sub levels {
661 my $ctx = shift;
662 $ctx->[1] = 0;
663 $ctx->[1] |= 1 << $_
664 for &_lvl_lst;
665 AnyEvent::Log::_reassess;
666 }
667
668 sub level {
669 my $ctx = shift;
670 my $lvl = $_[0] =~ /^(?:0|off|none)$/ ? 0 : (_lvl_lst $_[0])[-1];
671
672 $ctx->[1] = ((1 << $lvl) - 1) << 1;
673 AnyEvent::Log::_reassess;
674 }
675
676 sub enable {
677 my $ctx = shift;
678 $ctx->[1] |= 1 << $_
679 for &_lvl_lst;
680 AnyEvent::Log::_reassess;
681 }
682
683 sub disable {
684 my $ctx = shift;
685 $ctx->[1] &= ~(1 << $_)
686 for &_lvl_lst;
687 AnyEvent::Log::_reassess;
688 }
689
690 =back
691
692 =head3 SLAVE CONTEXTS
693
694 The following methods attach and detach another logging context to a
695 logging context.
696
697 Log messages are propagated to all slave contexts, unless the logging
698 callback consumes the message.
699
700 =over 4
701
702 =item $ctx->attach ($ctx2[, $ctx3...])
703
704 Attaches the given contexts as slaves to this context. It is not an error
705 to add a context twice (the second add will be ignored).
706
707 A context can be specified either as package name or as a context object.
708
709 =item $ctx->detach ($ctx2[, $ctx3...])
710
711 Removes the given slaves from this context - it's not an error to attempt
712 to remove a context that hasn't been added.
713
714 A context can be specified either as package name or as a context object.
715
716 =item $ctx->slaves ($ctx2[, $ctx3...])
717
718 Replaces all slaves attached to this context by the ones given.
719
720 =cut
721
722 sub attach {
723 my $ctx = shift;
724
725 $ctx->[2]{$_+0} = $_
726 for map { AnyEvent::Log::ctx $_ } @_;
727 }
728
729 sub detach {
730 my $ctx = shift;
731
732 delete $ctx->[2]{$_+0}
733 for map { AnyEvent::Log::ctx $_ } @_;
734 }
735
736 sub slaves {
737 undef $_[0][2];
738 &attach;
739 }
740
741 =back
742
743 =head3 LOG TARGETS
744
745 The following methods configure how the logging context actually does
746 the logging (which consists of formatting the message and printing it or
747 whatever it wants to do with it).
748
749 =over 4
750
751 =item $ctx->log_cb ($cb->($str)
752
753 Replaces the logging callback on the context (C<undef> disables the
754 logging callback).
755
756 The logging callback is responsible for handling formatted log messages
757 (see C<fmt_cb> below) - normally simple text strings that end with a
758 newline (and are possibly multiline themselves).
759
760 It also has to return true iff it has consumed the log message, and false
761 if it hasn't. Consuming a message means that it will not be sent to any
762 slave context. When in doubt, return C<0> from your logging callback.
763
764 Example: a very simple logging callback, simply dump the message to STDOUT
765 and do not consume it.
766
767 $ctx->log_cb (sub { print STDERR shift; 0 });
768
769 You can filter messages by having a log callback that simply returns C<1>
770 and does not do anything with the message, but this counts as "message
771 being logged" and might not be very efficient.
772
773 Example: propagate all messages except for log levels "debug" and
774 "trace". The messages will still be generated, though, which can slow down
775 your program.
776
777 $ctx->levels ("debug", "trace");
778 $ctx->log_cb (sub { 1 }); # do not log, but eat debug and trace messages
779
780 =item $ctx->fmt_cb ($fmt_cb->($timestamp, $orig_ctx, $level, $message))
781
782 Replaces the formatting callback on the context (C<undef> restores the
783 default formatter).
784
785 The callback is passed the (possibly fractional) timestamp, the original
786 logging context, the (numeric) logging level and the raw message string
787 and needs to return a formatted log message. In most cases this will be a
788 string, but it could just as well be an array reference that just stores
789 the values.
790
791 If, for some reason, you want to use C<caller> to find out more baout the
792 logger then you should walk up the call stack until you are no longer
793 inside the C<AnyEvent::Log> package.
794
795 Example: format just the raw message, with numeric log level in angle
796 brackets.
797
798 $ctx->fmt_cb (sub {
799 my ($time, $ctx, $lvl, $msg) = @_;
800
801 "<$lvl>$msg\n"
802 });
803
804 Example: return an array reference with just the log values, and use
805 C<PApp::SQL::sql_exec> to store the emssage in a database.
806
807 $ctx->fmt_cb (sub { \@_ });
808 $ctx->log_cb (sub {
809 my ($msg) = @_;
810
811 sql_exec "insert into log (when, subsys, prio, msg) values (?, ?, ?, ?)",
812 $msg->[0] + 0,
813 "$msg->[1]",
814 $msg->[2] + 0,
815 "$msg->[3]";
816
817 0
818 });
819
820 =item $ctx->log_to_warn
821
822 Sets the C<log_cb> to simply use C<CORE::warn> to report any messages
823 (usually this logs to STDERR).
824
825 =item $ctx->log_to_file ($path)
826
827 Sets the C<log_cb> to log to a file (by appending), unbuffered.
828
829 =item $ctx->log_to_path ($path)
830
831 Same as C<< ->log_to_file >>, but opens the file for each message. This
832 is much slower, but allows you to change/move/rename/delete the file at
833 basically any time.
834
835 Needless(?) to say, if you do not want to be bitten by some evil person
836 calling C<chdir>, the path should be absolute. Doesn't help with
837 C<chroot>, but hey...
838
839 =item $ctx->log_to_syslog ([$log_flags])
840
841 Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and all
842 the others in the obvious way. If specified, then the C<$log_flags> are
843 simply or'ed onto the priority argument and can contain any C<LOG_xxx>
844 flags valid for Sys::Syslog::syslog, except for the priority levels.
845
846 Note that this function also sets a C<fmt_cb> - the logging part requires
847 an array reference with [$level, $str] as input.
848
849 =cut
850
851 sub log_cb {
852 my ($ctx, $cb) = @_;
853
854 $ctx->[3] = $cb;
855 }
856
857 sub fmt_cb {
858 my ($ctx, $cb) = @_;
859
860 $ctx->[4] = $cb;
861 }
862
863 sub log_to_warn {
864 my ($ctx, $path) = @_;
865
866 $ctx->log_cb (sub {
867 warn shift;
868 0
869 });
870 }
871
872 sub log_to_file {
873 my ($ctx, $path) = @_;
874
875 open my $fh, ">>", $path
876 or die "$path: $!";
877
878 $ctx->log_cb (sub {
879 syswrite $fh, shift;
880 0
881 });
882 }
883
884 sub log_to_path {
885 my ($ctx, $path) = @_;
886
887 $ctx->log_cb (sub {
888 open my $fh, ">>", $path
889 or die "$path: $!";
890
891 syswrite $fh, shift;
892 0
893 });
894 }
895
896 sub log_to_syslog {
897 my ($ctx, $flags) = @_;
898
899 require Sys::Syslog;
900
901 $ctx->fmt_cb (sub {
902 my $str = $_[3];
903 $str =~ s/\n(?=.)/\n+ /g;
904
905 [$_[2], "($_[1][0]) $str"]
906 });
907
908 $ctx->log_cb (sub {
909 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
910
911 Sys::Syslog::syslog ($flags | ($lvl - 1), $_)
912 for split /\n/, $_[0][1];
913
914 0
915 });
916 }
917
918 =back
919
920 =head3 MESSAGE LOGGING
921
922 These methods allow you to log messages directly to a context, without
923 going via your package context.
924
925 =over 4
926
927 =item $ctx->log ($level, $msg[, @params])
928
929 Same as C<AnyEvent::Log::log>, but uses the given context as log context.
930
931 =item $logger = $ctx->logger ($level[, \$enabled])
932
933 Same as C<AnyEvent::Log::logger>, but uses the given context as log
934 context.
935
936 =cut
937
938 *log = \&AnyEvent::Log::_log;
939 *logger = \&AnyEvent::Log::_logger;
940
941 =back
942
943 =cut
944
945 package AnyEvent::Log;
946
947 =head1 CONFIGURATION VIA $ENV{PERL_ANYEVENT_LOG}
948
949 Logging can also be configured by setting the environment variable
950 C<PERL_ANYEVENT_LOG> (or C<AE_LOG>).
951
952 The value consists of one or more logging context specifications separated
953 by C<:> or whitespace. Each logging specification in turn starts with a
954 context name, followed by C<=>, followed by zero or more comma-separated
955 configuration directives, here are some examples:
956
957 # set default logging level
958 filter=warn
959
960 # log to file instead of to stderr
961 log=file=/tmp/mylog
962
963 # log to file in addition to stderr
964 log=+%file:%file=file=/tmp/mylog
965
966 # enable debug log messages, log warnings and above to syslog
967 filter=debug:log=+%warnings:%warnings=warn,syslog=LOG_LOCAL0
968
969 # log trace messages (only) from AnyEvent::Debug to file
970 AnyEvent::Debug=+%trace:%trace=only,trace,file=/tmp/tracelog
971
972 A context name in the log specification can be any of the following:
973
974 =over 4
975
976 =item C<collect>, C<filter>, C<log>
977
978 Correspond to the three predefined C<$AnyEvent::Log::COLLECT>,
979 C<AnyEvent::Log::FILTER> and C<$AnyEvent::Log::LOG> contexts.
980
981 =item C<%name>
982
983 Context names starting with a C<%> are anonymous contexts created when the
984 name is first mentioned. The difference to package contexts is that by
985 default they have no attached slaves.
986
987 =item a perl package name
988
989 Any other string references the logging context associated with the given
990 Perl C<package>. In the unlikely case where you want to specify a package
991 context that matches on of the other context name forms, you can add a
992 C<::> to the package name to force interpretation as a package.
993
994 =back
995
996 The configuration specifications can be any number of the following:
997
998 =over 4
999
1000 =item C<stderr>
1001
1002 Configures the context to use Perl's C<warn> function (which typically
1003 logs to C<STDERR>). Works like C<log_to_warn>.
1004
1005 =item C<file=>I<path>
1006
1007 Configures the context to log to a file with the given path. Works like
1008 C<log_to_file>.
1009
1010 =item C<path=>I<path>
1011
1012 Configures the context to log to a file with the given path. Works like
1013 C<log_to_path>.
1014
1015 =item C<syslog> or C<syslog=>I<expr>
1016
1017 Configured the context to log to syslog. If I<expr> is given, then it is
1018 evaluated in the L<Sys::Syslog> package, so you could use:
1019
1020 log=syslog=LOG_LOCAL0
1021
1022 =item C<nolog>
1023
1024 Configures the context to not log anything by itself, which is the
1025 default. Same as C<< $ctx->log_cb (undef) >>.
1026
1027 =item C<0> or C<off>
1028
1029 Sets the logging level of the context ot C<0>, i.e. all messages will be
1030 filtered out.
1031
1032 =item C<all>
1033
1034 Enables all logging levels, i.e. filtering will effectively be switched
1035 off (the default).
1036
1037 =item C<only>
1038
1039 Disables all logging levels, and changes the interpretation of following
1040 level specifications to enable the specified level only.
1041
1042 Example: only enable debug messages for a context.
1043
1044 context=only,debug
1045
1046 =item C<except>
1047
1048 Enables all logging levels, and changes the interpretation of following
1049 level specifications to disable that level. Rarely used.
1050
1051 Example: enable all logging levels except fatal and trace (this is rather
1052 nonsensical).
1053
1054 filter=exept,fatal,trace
1055
1056 =item C<level>
1057
1058 Enables all logging levels, and changes the interpretation of following
1059 level specifications to be "that level or any higher priority
1060 message". This is the default.
1061
1062 Example: log anything at or above warn level.
1063
1064 filter=warn
1065
1066 # or, more verbose
1067 filter=only,level,warn
1068
1069 =item C<1>..C<9>, a logging level name (C<error>, C<debug> etc.)
1070
1071 A numeric loglevel or the name of a loglevel will be interpreted according
1072 to the most recent C<only>, C<except> or C<level> directive. By default,
1073 specifying a logging level enables that and any higher priority messages.
1074
1075 =item C<+>I<context>
1076
1077 Adds/attaches the named context as slave to the context.
1078
1079 =item C<+>
1080
1081 A line C<+> clears the slave list form the context. Anonymous (C<%name>)
1082 contexts have no slaves by default, but package contexts have the parent
1083 context as slave by default.
1084
1085 Example: log messages from My::Module to a file, do not send them to the
1086 default log collector.
1087
1088 My::Module=+,file=/tmp/mymodulelog
1089
1090 =back
1091
1092 =cut
1093
1094 for (my $spec = $ENV{PERL_ANYEVENT_LOG}) {
1095 my %anon;
1096
1097 my $pkg = sub {
1098 $_[0] eq "log" ? $LOG
1099 : $_[0] eq "filter" ? $FILTER
1100 : $_[0] eq "collect" ? $COLLECT
1101 : $_[0] =~ /^%(.+)$/ && $anon{$1} ||= ctx undef
1102 : $_[0] =~ /^(.*?)(?:::)?$/ && ctx "$1" # egad :/
1103 };
1104
1105 while (/\G((?:[^:=]+|::|\\.)+)=/gc) {
1106 my $ctx = $pkg->($1);
1107 my $level = "level";
1108
1109 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
1110 for ("$1") {
1111 if ($_ eq "stderr" ) { $ctx->log_to_warn;
1112 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
1113 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
1114 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog (eval "package Sys::Syslog; $1");
1115 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
1116 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
1117 } elsif ($_ eq "+" ) { $ctx->slaves;
1118 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
1119 } elsif ($_ eq "all" ) { $ctx->level ("all");
1120 } elsif ($_ eq "level" ) { $ctx->level ("all"); $level = "level";
1121 } elsif ($_ eq "only" ) { $ctx->level ("off"); $level = "enable";
1122 } elsif ($_ eq "except" ) { $ctx->level ("all"); $level = "disable";
1123 } elsif (/^\d$/ ) { $ctx->$level ($_);
1124 } elsif (exists $STR2LEVEL{$_} ) { $ctx->$level ($_);
1125 } else { die "PERL_ANYEVENT_LOG ($spec): parse error at '$_'\n";
1126 }
1127 }
1128
1129 /\G,/gc or last;
1130 }
1131
1132 /\G[:[:space:]]/gc or last;
1133 }
1134
1135 if (/\G(.+)/g) {
1136 die "PERL_ANYEVENT_LOG ($spec): parse error at '$1'\n";
1137 }
1138 }
1139
1140 1;
1141
1142 =head1 EXAMPLES
1143
1144 This section shows some common configurations.
1145
1146 =over 4
1147
1148 =item Setting the global logging level.
1149
1150 Either put PERL_ANYEVENT_VERBOSE=<number> into your environment before
1151 running your program, or modify the log level of the root context:
1152
1153 PERL_ANYEVENT_VERBOSE=5 ./myprog
1154
1155 $AnyEvent::Log::FILTER->level ("warn");
1156
1157 =item Append all messages to a file instead of sending them to STDERR.
1158
1159 This is affected by the global logging level.
1160
1161 $AnyEvent::Log::LOG->log_to_file ($path); (sub {
1162
1163 =item Write all messages with priority C<error> and higher to a file.
1164
1165 This writes them only when the global logging level allows it, because
1166 it is attached to the default context which is invoked I<after> global
1167 filtering.
1168
1169 $AnyEvent::Log::FILTER->attach
1170 new AnyEvent::Log::Ctx log_to_file => $path);
1171
1172 This writes them regardless of the global logging level, because it is
1173 attached to the toplevel context, which receives all messages I<before>
1174 the global filtering.
1175
1176 $AnyEvent::Log::COLLECT->attach (
1177 new AnyEvent::Log::Ctx log_to_file => $path);
1178
1179 In both cases, messages are still written to STDERR.
1180
1181 =item Write trace messages (only) from L<AnyEvent::Debug> to the default logging target(s).
1182
1183 Attach the C<$AnyEvent::Log::LOG> context to the C<AnyEvent::Debug>
1184 context - this simply circumvents the global filtering for trace messages.
1185
1186 my $debug = AnyEvent::Debug->AnyEvent::Log::ctx;
1187 $debug->attach ($AnyEvent::Log::LOG);
1188
1189 This of course works for any package, not just L<AnyEvent::Debug>, but
1190 assumes the log level for AnyEvent::Debug hasn't been changed from the
1191 default.
1192
1193 =back
1194
1195 =head1 AUTHOR
1196
1197 Marc Lehmann <schmorp@schmorp.de>
1198 http://home.schmorp.de/
1199
1200 =cut