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.36 by root, Thu Aug 25 05:39:47 2011 UTC vs.
Revision 1.44 by root, Mon Sep 26 11:32:19 2011 UTC

… …
6 6
7Simple uses: 7Simple uses:
8 8
9 use AnyEvent; 9 use AnyEvent;
10 10
11 AE::log debug => "hit my knee"; 11 AE::log trace => "going to call function abc";
12 AE::log warn => "it's a bit too hot"; 12 AE::log debug => "the function returned 3";
13 AE::log error => "the flag was false!"; 13 AE::log info => "file soandso successfully deleted";
14 AE::log fatal => "the bit toggled! run!"; # never returns 14 AE::log note => "wanted to create config, but config was alraedy created";
15 AE::log warn => "couldn't delete the file";
16 AE::log error => "failed to retrieve data";
17 AE::log crit => "the battery temperature is too hot";
18 AE::log alert => "the battery died";
19 AE::log fatal => "no config found, cannot continue"; # never returns
15 20
21Log level overview:
22
23 LVL NAME SYSLOG PERL NOTE
24 1 fatal emerg exit system unusable, aborts program!
25 2 alert failure in primary system
26 3 critical crit failure in backup system
27 4 error err die non-urgent program errors, a bug
28 5 warn warning possible problem, not necessarily error
29 6 note notice unusual conditions
30 7 info normal messages, no action required
31 8 debug debugging messages for development
32 9 trace copious tracing output
33
16"Complex" uses (for speed sensitive code): 34"Complex" uses (for speed sensitive code, e.g. trace/debug messages):
17 35
18 use AnyEvent::Log; 36 use AnyEvent::Log;
19 37
20 my $tracer = AnyEvent::Log::logger trace => \$my $trace; 38 my $tracer = AnyEvent::Log::logger trace => \$my $trace;
21 39
… …
32 50
33 # send all critical and higher priority messages to syslog, 51 # send all critical and higher priority messages to syslog,
34 # regardless of (most) other settings 52 # regardless of (most) other settings
35 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx 53 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
36 level => "critical", 54 level => "critical",
37 log_to_syslog => 0, 55 log_to_syslog => "user",
38 ); 56 );
39 57
40=head1 DESCRIPTION 58=head1 DESCRIPTION
41 59
42This module implements a relatively simple "logging framework". It doesn't 60This module implements a relatively simple "logging framework". It doesn't
… …
72numerical value". 90numerical value".
73 91
74Instead of specifying levels by name you can also specify them by aliases: 92Instead of specifying levels by name you can also specify them by aliases:
75 93
76 LVL NAME SYSLOG PERL NOTE 94 LVL NAME SYSLOG PERL NOTE
77 1 fatal emerg exit aborts program! 95 1 fatal emerg exit system unusable, aborts program!
78 2 alert 96 2 alert failure in primary system
79 3 critical crit 97 3 critical crit failure in backup system
80 4 error err die 98 4 error err die non-urgent program errors, a bug
81 5 warn warning 99 5 warn warning possible problem, not necessarily error
82 6 note notice 100 6 note notice unusual conditions
83 7 info 101 7 info normal messages, no action required
84 8 debug 102 8 debug debugging messages for development
85 9 trace 103 9 trace copious tracing output
86 104
87As you can see, some logging levels have multiple aliases - the first one 105As you can see, some logging levels have multiple aliases - the first one
88is the "official" name, the second one the "syslog" name (if it differs) 106is the "official" name, the second one the "syslog" name (if it differs)
89and the third one the "perl" name, suggesting that you log C<die> messages 107and the third one the "perl" name, suggesting (only!) that you log C<die>
90at C<error> priority. 108messages at C<error> priority. The NOTE column tries to provide some
109rationale on how to chose a logging level.
110
111As a rough guideline, levels 1..3 are primarily meant for users of
112the program (admins, staff), and are the only logged to STDERR by
113default. Levels 4..6 are meant for users and developers alike, while
114levels 7..9 are usually meant for developers.
91 115
92You can normally only log a single message at highest priority level 116You can normally only log a single message at highest priority level
93(C<1>, C<fatal>), because logging a fatal message will also quit the 117(C<1>, C<fatal>), because logging a fatal message will also quit the
94program - so use it sparingly :) 118program - so use it sparingly :)
95 119
… …
111 135
112use Carp (); 136use Carp ();
113use POSIX (); 137use POSIX ();
114 138
115use AnyEvent (); BEGIN { AnyEvent::common_sense } 139use AnyEvent (); BEGIN { AnyEvent::common_sense }
116use AnyEvent::Util (); 140#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
117 141
118our $VERSION = $AnyEvent::VERSION; 142our $VERSION = $AnyEvent::VERSION;
119 143
120our ($COLLECT, $FILTER, $LOG); 144our ($COLLECT, $FILTER, $LOG);
121 145
… …
151=item AnyEvent::Log::log $level, $msg[, @args] 175=item AnyEvent::Log::log $level, $msg[, @args]
152 176
153Requests logging of the given C<$msg> with the given log level, and 177Requests logging of the given C<$msg> with the given log level, and
154returns true if the message was logged I<somewhere>. 178returns true if the message was logged I<somewhere>.
155 179
156For C<fatal> log levels, the program will abort. 180For loglevel C<fatal>, the program will abort.
157 181
158If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the 182If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the
159C<$msg> is interpreted as an sprintf format string. 183C<$msg> is interpreted as an sprintf format string.
160 184
161The C<$msg> should not end with C<\n>, but may if that is convenient for 185The C<$msg> should not end with C<\n>, but may if that is convenient for
… …
206 info => 7, 230 info => 7,
207 debug => 8, 231 debug => 8,
208 trace => 9, 232 trace => 9,
209); 233);
210 234
211sub now () { time } 235our $TIME_EXACT;
236
237sub exact_time($) {
238 $TIME_EXACT = shift;
239 *_ts = $AnyEvent::MODEL
240 ? $TIME_EXACT ? \&AE::now : \&AE::time
241 : sub () { $TIME_EXACT ? do { require Time::HiRes; Time::HiRes::time () } : time };
242}
243
244BEGIN {
245 exact_time 0;
246}
212 247
213AnyEvent::post_detect { 248AnyEvent::post_detect {
214 *now = \&AE::now; 249 exact_time $TIME_EXACT;
215}; 250};
216 251
217our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); 252our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
218 253
219# time, ctx, level, msg 254# time, ctx, level, msg
… …
227 push @res, "$ts$ct$_\n"; 262 push @res, "$ts$ct$_\n";
228 $ct = " + "; 263 $ct = " + ";
229 } 264 }
230 265
231 join "", @res 266 join "", @res
267}
268
269sub fatal_exit() {
270 exit 1;
232} 271}
233 272
234sub _log { 273sub _log {
235 my ($ctx, $level, $format, @args) = @_; 274 my ($ctx, $level, $format, @args) = @_;
236 275
… …
252 # now get raw message, unless we have it already 291 # now get raw message, unless we have it already
253 unless ($now) { 292 unless ($now) {
254 $format = $format->() if ref $format; 293 $format = $format->() if ref $format;
255 $format = sprintf $format, @args if @args; 294 $format = sprintf $format, @args if @args;
256 $format =~ s/\n$//; 295 $format =~ s/\n$//;
257 $now = now; 296 $now = _ts;
258 }; 297 };
259 298
260 # format msg 299 # format msg
261 my $str = $ctx->[4] 300 my $str = $ctx->[4]
262 ? $ctx->[4]($now, $_[0], $level, $format) 301 ? $ctx->[4]($now, $_[0], $level, $format)
… …
271 } 310 }
272 } 311 }
273 } 312 }
274 while $ctx = pop @ctx; 313 while $ctx = pop @ctx;
275 314
276 exit 1 if $level <= 1; 315 fatal_exit if $level <= 1;
277 316
278 $success 317 $success
279} 318}
280 319
281sub log($$;@) { 320sub log($$;@) {
282 _log 321 _log
283 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0], 322 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
284 @_; 323 @_;
285} 324}
286 325
287*AnyEvent::log = *AE::log = \&log;
288
289=item $logger = AnyEvent::Log::logger $level[, \$enabled] 326=item $logger = AnyEvent::Log::logger $level[, \$enabled]
290 327
291Creates a code reference that, when called, acts as if the 328Creates a code reference that, when called, acts as if the
292C<AnyEvent::Log::log> function was called at this point with the given 329C<AnyEvent::Log::log> function was called at this point with the given
293level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with 330level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with
… …
357 394
358 $LOGGER{$logger+0} = $logger; 395 $LOGGER{$logger+0} = $logger;
359 396
360 _reassess $logger+0; 397 _reassess $logger+0;
361 398
399 require AnyEvent::Util unless $AnyEvent::Util::VERSION;
362 my $guard = AnyEvent::Util::guard { 400 my $guard = AnyEvent::Util::guard (sub {
363 # "clean up" 401 # "clean up"
364 delete $LOGGER{$logger+0}; 402 delete $LOGGER{$logger+0};
365 }; 403 });
366 404
367 sub { 405 sub {
368 $guard if 0; # keep guard alive, but don't cause runtime overhead 406 $guard if 0; # keep guard alive, but don't cause runtime overhead
369 407
370 _log $ctx, $level, @_ 408 _log $ctx, $level, @_
… …
375sub logger($;$) { 413sub logger($;$) {
376 _logger 414 _logger
377 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0], 415 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
378 @_ 416 @_
379} 417}
418
419=item AnyEvent::Log::exact_time $on
420
421By default, C<AnyEvent::Log> will use C<AE::now>, i.e. the cached
422eventloop time, for the log timestamps. After calling this function with a
423true value it will instead resort to C<AE::time>, i.e. fetch the current
424time on each log message. This only makes a difference for event loops
425that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
426
427This setting can be changed at any time by calling this function.
428
429Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been
430initialised, this switch will also decide whether to use C<CORE::time> or
431C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
432available.
380 433
381=back 434=back
382 435
383=head1 LOGGING CONTEXTS 436=head1 LOGGING CONTEXTS
384 437
… …
504This can be used to implement config-file (re-)loading: before loading a 557This can be used to implement config-file (re-)loading: before loading a
505configuration, reset all contexts. 558configuration, reset all contexts.
506 559
507=cut 560=cut
508 561
562our $ORIG_VERBOSE = $AnyEvent::VERBOSE;
563$AnyEvent::VERBOSE = 9;
564
509sub reset { 565sub reset {
510 # hard to kill complex data structures 566 # hard to kill complex data structures
511 # we "recreate" all package loggers and reset the hierarchy 567 # we "recreate" all package loggers and reset the hierarchy
512 while (my ($k, $v) = each %CTX) { 568 while (my ($k, $v) = each %CTX) {
513 @$v = ($k, (1 << 10) - 1 - 1, { }); 569 @$v = ($k, (1 << 10) - 1 - 1, { });
… …
522 $LOG->title ('$AnyEvent::Log::LOG'); 578 $LOG->title ('$AnyEvent::Log::LOG');
523 $LOG->log_to_warn; 579 $LOG->log_to_warn;
524 580
525 $FILTER->slaves ($LOG); 581 $FILTER->slaves ($LOG);
526 $FILTER->title ('$AnyEvent::Log::FILTER'); 582 $FILTER->title ('$AnyEvent::Log::FILTER');
527 $FILTER->level ($AnyEvent::VERBOSE); 583 $FILTER->level ($ORIG_VERBOSE);
528 584
529 $COLLECT->slaves ($FILTER); 585 $COLLECT->slaves ($FILTER);
530 $COLLECT->title ('$AnyEvent::Log::COLLECT'); 586 $COLLECT->title ('$AnyEvent::Log::COLLECT');
531 587
532 _reassess; 588 _reassess;
533} 589}
590
591# override AE::log/logger
592*AnyEvent::log = *AE::log = \&log;
593*AnyEvent::logger = *AE::logger = \&logger;
594
595# convert AnyEvent loggers to AnyEvent::Log loggers
596$_->[0] = ctx $_->[0] # convert "pkg" to "ctx"
597 for values %LOGGER;
534 598
535# create the default logger contexts 599# create the default logger contexts
536$LOG = ctx undef; 600$LOG = ctx undef;
537$FILTER = ctx undef; 601$FILTER = ctx undef;
538$COLLECT = ctx undef; 602$COLLECT = ctx undef;
… …
837 901
838Needless(?) to say, if you do not want to be bitten by some evil person 902Needless(?) to say, if you do not want to be bitten by some evil person
839calling C<chdir>, the path should be absolute. Doesn't help with 903calling C<chdir>, the path should be absolute. Doesn't help with
840C<chroot>, but hey... 904C<chroot>, but hey...
841 905
842=item $ctx->log_to_syslog ([$log_flags]) 906=item $ctx->log_to_syslog ([$facility])
843 907
844Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and all 908Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and
845the others in the obvious way. If specified, then the C<$log_flags> are 909all the others in the obvious way. If specified, then the C<$facility> is
846simply or'ed onto the priority argument and can contain any C<LOG_xxx> 910used as the facility (C<user>, C<auth>, C<local0> and so on). The default
847flags valid for Sys::Syslog::syslog, except for the priority levels. 911facility is C<user>.
848 912
849Note that this function also sets a C<fmt_cb> - the logging part requires 913Note that this function also sets a C<fmt_cb> - the logging part requires
850an array reference with [$level, $str] as input. 914an array reference with [$level, $str] as input.
851 915
852=cut 916=cut
… …
895 0 959 0
896 }); 960 });
897} 961}
898 962
899sub log_to_syslog { 963sub log_to_syslog {
900 my ($ctx, $flags) = @_; 964 my ($ctx, $facility) = @_;
901 965
902 require Sys::Syslog; 966 require Sys::Syslog;
903 967
904 $ctx->fmt_cb (sub { 968 $ctx->fmt_cb (sub {
905 my $str = $_[3]; 969 my $str = $_[3];
906 $str =~ s/\n(?=.)/\n+ /g; 970 $str =~ s/\n(?=.)/\n+ /g;
907 971
908 [$_[2], "($_[1][0]) $str"] 972 [$_[2], "($_[1][0]) $str"]
909 }); 973 });
910 974
975 $facility ||= "user";
976
911 $ctx->log_cb (sub { 977 $ctx->log_cb (sub {
912 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8; 978 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
913 979
914 Sys::Syslog::syslog ($flags | ($lvl - 1), $_) 980 Sys::Syslog::syslog ("$facility|" . ($lvl - 1), $_)
915 for split /\n/, $_[0][1]; 981 for split /\n/, $_[0][1];
916 982
917 0 983 0
918 }); 984 });
919} 985}
… …
1136 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) { 1202 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
1137 for ("$1") { 1203 for ("$1") {
1138 if ($_ eq "stderr" ) { $ctx->log_to_warn; 1204 if ($_ eq "stderr" ) { $ctx->log_to_warn;
1139 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1"); 1205 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
1140 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1"); 1206 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
1141 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog (eval "package Sys::Syslog; $1"); 1207 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ($1);
1142 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef); 1208 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
1143 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1")); 1209 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
1144 } elsif ($_ eq "+" ) { $ctx->slaves; 1210 } elsif ($_ eq "+" ) { $ctx->slaves;
1145 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0); 1211 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
1146 } elsif ($_ eq "all" ) { $ctx->level ("all"); 1212 } elsif ($_ eq "all" ) { $ctx->level ("all");
… …
1199 1265
1200This writes them only when the global logging level allows it, because 1266This writes them only when the global logging level allows it, because
1201it is attached to the default context which is invoked I<after> global 1267it is attached to the default context which is invoked I<after> global
1202filtering. 1268filtering.
1203 1269
1204 $AnyEvent::Log::FILTER->attach 1270 $AnyEvent::Log::FILTER->attach (
1205 new AnyEvent::Log::Ctx log_to_file => $path); 1271 new AnyEvent::Log::Ctx log_to_file => $path);
1206 1272
1207 PERL_ANYEVENT_LOG=filter=+%filelogger:%filelogger=file=/some/path 1273 PERL_ANYEVENT_LOG=filter=+%filelogger:%filelogger=file=/some/path
1208 1274
1209This writes them regardless of the global logging level, because it is 1275This writes them regardless of the global logging level, because it is

Diff Legend

– Removed lines
+ Added lines
< Changed lines
> Changed lines