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.8 by root, Fri Aug 19 19:20:36 2011 UTC vs.
Revision 1.32 by root, Thu Aug 25 04:56:16 2011 UTC

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

Diff Legend

Removed lines
+ Added lines
< Changed lines
> Changed lines