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.31 by root, Thu Aug 25 03:08:48 2011 UTC vs.
Revision 1.42 by root, Thu Sep 1 22:38:11 2011 UTC

… …
11 AE::log debug => "hit my knee"; 11 AE::log debug => "hit my knee";
12 AE::log warn => "it's a bit too hot"; 12 AE::log warn => "it's a bit too hot";
13 AE::log error => "the flag was false!"; 13 AE::log error => "the flag was false!";
14 AE::log fatal => "the bit toggled! run!"; # never returns 14 AE::log fatal => "the bit toggled! run!"; # never returns
15 15
16 # available log levels in order:
17 # fatal alert critical error warn note info debug trace
18
16"Complex" uses (for speed sensitive code): 19"Complex" uses (for speed sensitive code):
17 20
18 use AnyEvent::Log; 21 use AnyEvent::Log;
19 22
20 my $tracer = AnyEvent::Log::logger trace => \$my $trace; 23 my $tracer = AnyEvent::Log::logger trace => \$my $trace;
… …
32 35
33 # send all critical and higher priority messages to syslog, 36 # send all critical and higher priority messages to syslog,
34 # regardless of (most) other settings 37 # regardless of (most) other settings
35 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx 38 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
36 level => "critical", 39 level => "critical",
37 log_to_syslog => 0, 40 log_to_syslog => "user",
38 ); 41 );
39 42
40=head1 DESCRIPTION 43=head1 DESCRIPTION
41 44
42This module implements a relatively simple "logging framework". It doesn't 45This module implements a relatively simple "logging framework". It doesn't
… …
49will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number 52will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number
50before starting your program, or change the logging level at runtime with 53before starting your program, or change the logging level at runtime with
51something like: 54something like:
52 55
53 use AnyEvent::Log; 56 use AnyEvent::Log;
54 AnyEvent::Log::FILTER->level ("info"); 57 $AnyEvent::Log::FILTER->level ("info");
55 58
56The design goal behind this module was to keep it simple (and small), 59The 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 60but make it powerful enough to be potentially useful for any module, and
58extensive enough for the most common tasks, such as logging to multiple 61extensive enough for the most common tasks, such as logging to multiple
59targets, or being able to log into a database. 62targets, or being able to log into a database.
60 63
64The module is also usable before AnyEvent itself is initialised, in which
65case some of the functionality might be reduced.
66
61The amount of documentation might indicate otherwise, but the module is 67The amount of documentation might indicate otherwise, but the runtime part
62still just below 300 lines of code. 68of the module is still just below 300 lines of code.
63 69
64=head1 LOGGING LEVELS 70=head1 LOGGING LEVELS
65 71
66Logging levels in this module range from C<1> (highest priority) to C<9> 72Logging 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 73(lowest priority). Note that the lowest numerical value is the highest
… …
69numerical value". 75numerical value".
70 76
71Instead of specifying levels by name you can also specify them by aliases: 77Instead of specifying levels by name you can also specify them by aliases:
72 78
73 LVL NAME SYSLOG PERL NOTE 79 LVL NAME SYSLOG PERL NOTE
74 1 fatal emerg exit aborts program! 80 1 fatal emerg exit system unusable, aborts program!
75 2 alert 81 2 alert failure in primary system
76 3 critical crit 82 3 critical crit failure in backup system
77 4 error err die 83 4 error err die non-urgent program errors, a bug
78 5 warn warning 84 5 warn warning possible problem, not necessarily error
79 6 note notice 85 6 note notice unusual conditions
80 7 info 86 7 info normal messages, no action required
81 8 debug 87 8 debug debugging messages for development
82 9 trace 88 9 trace copious tracing output
83 89
84As you can see, some logging levels have multiple aliases - the first one 90As 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) 91is 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 92and the third one the "perl" name, suggesting (only!) that you log C<die>
87at C<error> priority. 93messages at C<error> priority. The NOTE column tries to provide some
94rationale on how to chose a logging level.
95
96As a rough guideline, levels 1..3 are primarily meant for users of
97the program (admins, staff), and are the only logged to STDERR by
98default. Levels 4..6 are meant for users and developers alike, while
99levels 7..9 are usually meant for developers.
88 100
89You can normally only log a single message at highest priority level 101You 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 102(C<1>, C<fatal>), because logging a fatal message will also quit the
91program - so use it sparingly :) 103program - so use it sparingly :)
92 104
… …
108 120
109use Carp (); 121use Carp ();
110use POSIX (); 122use POSIX ();
111 123
112use AnyEvent (); BEGIN { AnyEvent::common_sense } 124use AnyEvent (); BEGIN { AnyEvent::common_sense }
113use AnyEvent::Util (); 125#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
114 126
115our $VERSION = $AnyEvent::VERSION; 127our $VERSION = $AnyEvent::VERSION;
116 128
117our ($COLLECT, $FILTER, $LOG); 129our ($COLLECT, $FILTER, $LOG);
118 130
… …
148=item AnyEvent::Log::log $level, $msg[, @args] 160=item AnyEvent::Log::log $level, $msg[, @args]
149 161
150Requests logging of the given C<$msg> with the given log level, and 162Requests logging of the given C<$msg> with the given log level, and
151returns true if the message was logged I<somewhere>. 163returns true if the message was logged I<somewhere>.
152 164
153For C<fatal> log levels, the program will abort. 165For loglevel C<fatal>, the program will abort.
154 166
155If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the 167If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the
156C<$msg> is interpreted as an sprintf format string. 168C<$msg> is interpreted as an sprintf format string.
157 169
158The C<$msg> should not end with C<\n>, but may if that is convenient for 170The C<$msg> should not end with C<\n>, but may if that is convenient for
… …
203 info => 7, 215 info => 7,
204 debug => 8, 216 debug => 8,
205 trace => 9, 217 trace => 9,
206); 218);
207 219
208sub now () { time } 220our $TIME_EXACT;
221
222sub exact_time($) {
223 $TIME_EXACT = shift;
224 *_ts = $AnyEvent::MODEL
225 ? $TIME_EXACT ? \&AE::now : \&AE::time
226 : sub () { $TIME_EXACT ? do { require Time::HiRes; Time::HiRes::time () } : time };
227}
228
229BEGIN {
230 exact_time 0;
231}
209 232
210AnyEvent::post_detect { 233AnyEvent::post_detect {
211 *now = \&AE::now; 234 exact_time $TIME_EXACT;
212}; 235};
213 236
214our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); 237our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
215 238
216# time, ctx, level, msg 239# time, ctx, level, msg
… …
249 # now get raw message, unless we have it already 272 # now get raw message, unless we have it already
250 unless ($now) { 273 unless ($now) {
251 $format = $format->() if ref $format; 274 $format = $format->() if ref $format;
252 $format = sprintf $format, @args if @args; 275 $format = sprintf $format, @args if @args;
253 $format =~ s/\n$//; 276 $format =~ s/\n$//;
254 $now = now; 277 $now = _ts;
255 }; 278 };
256 279
257 # format msg 280 # format msg
258 my $str = $ctx->[4] 281 my $str = $ctx->[4]
259 ? $ctx->[4]($now, $_[0], $level, $format) 282 ? $ctx->[4]($now, $_[0], $level, $format)
… …
354 377
355 $LOGGER{$logger+0} = $logger; 378 $LOGGER{$logger+0} = $logger;
356 379
357 _reassess $logger+0; 380 _reassess $logger+0;
358 381
382 require AnyEvent::Util;
359 my $guard = AnyEvent::Util::guard { 383 my $guard = AnyEvent::Util::guard (sub {
360 # "clean up" 384 # "clean up"
361 delete $LOGGER{$logger+0}; 385 delete $LOGGER{$logger+0};
362 }; 386 });
363 387
364 sub { 388 sub {
365 $guard if 0; # keep guard alive, but don't cause runtime overhead 389 $guard if 0; # keep guard alive, but don't cause runtime overhead
366 390
367 _log $ctx, $level, @_ 391 _log $ctx, $level, @_
… …
372sub logger($;$) { 396sub logger($;$) {
373 _logger 397 _logger
374 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0], 398 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
375 @_ 399 @_
376} 400}
401
402=item AnyEvent::Log::exact_time $on
403
404By default, C<AnyEvent::Log> will use C<AE::now>, i.e. the cached
405eventloop time, for the log timestamps. After calling this function with a
406true value it will instead resort to C<AE::time>, i.e. fetch the current
407time on each log message. This only makes a difference for event loops
408that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
409
410This setting can be changed at any time by calling this function.
411
412Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been
413initialised, this switch will also decide whether to use C<CORE::time> or
414C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
415available.
377 416
378=back 417=back
379 418
380=head1 LOGGING CONTEXTS 419=head1 LOGGING CONTEXTS
381 420
… …
513 } 552 }
514 553
515 @$_ = ($_->[0], (1 << 10) - 1 - 1) 554 @$_ = ($_->[0], (1 << 10) - 1 - 1)
516 for $LOG, $FILTER, $COLLECT; 555 for $LOG, $FILTER, $COLLECT;
517 556
518 $LOG->slaves; 557 #$LOG->slaves;
519 $LOG->title ('$AnyEvent::Log::LOG'); 558 $LOG->title ('$AnyEvent::Log::LOG');
520 $LOG->log_to_warn; 559 $LOG->log_to_warn;
521 560
522 $FILTER->slaves ($LOG); 561 $FILTER->slaves ($LOG);
523 $FILTER->title ('$AnyEvent::Log::FILTER'); 562 $FILTER->title ('$AnyEvent::Log::FILTER');
… …
834 873
835Needless(?) to say, if you do not want to be bitten by some evil person 874Needless(?) 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 875calling C<chdir>, the path should be absolute. Doesn't help with
837C<chroot>, but hey... 876C<chroot>, but hey...
838 877
839=item $ctx->log_to_syslog ([$log_flags]) 878=item $ctx->log_to_syslog ([$facility])
840 879
841Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and all 880Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and
842the others in the obvious way. If specified, then the C<$log_flags> are 881all the others in the obvious way. If specified, then the C<$facility> is
843simply or'ed onto the priority argument and can contain any C<LOG_xxx> 882used as the facility (C<user>, C<auth>, C<local0> and so on). The default
844flags valid for Sys::Syslog::syslog, except for the priority levels. 883facility is C<user>.
845 884
846Note that this function also sets a C<fmt_cb> - the logging part requires 885Note that this function also sets a C<fmt_cb> - the logging part requires
847an array reference with [$level, $str] as input. 886an array reference with [$level, $str] as input.
848 887
849=cut 888=cut
… …
892 0 931 0
893 }); 932 });
894} 933}
895 934
896sub log_to_syslog { 935sub log_to_syslog {
897 my ($ctx, $flags) = @_; 936 my ($ctx, $facility) = @_;
898 937
899 require Sys::Syslog; 938 require Sys::Syslog;
900 939
901 $ctx->fmt_cb (sub { 940 $ctx->fmt_cb (sub {
902 my $str = $_[3]; 941 my $str = $_[3];
903 $str =~ s/\n(?=.)/\n+ /g; 942 $str =~ s/\n(?=.)/\n+ /g;
904 943
905 [$_[2], "($_[1][0]) $str"] 944 [$_[2], "($_[1][0]) $str"]
906 }); 945 });
907 946
947 $facility ||= "user";
948
908 $ctx->log_cb (sub { 949 $ctx->log_cb (sub {
909 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8; 950 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
910 951
911 Sys::Syslog::syslog ($flags | ($lvl - 1), $_) 952 Sys::Syslog::syslog ("$facility|" . ($lvl - 1), $_)
912 for split /\n/, $_[0][1]; 953 for split /\n/, $_[0][1];
913 954
914 0 955 0
915 }); 956 });
916} 957}
… …
1012Configures the context to log to a file with the given path. Works like 1053Configures the context to log to a file with the given path. Works like
1013C<log_to_path>. 1054C<log_to_path>.
1014 1055
1015=item C<syslog> or C<syslog=>I<expr> 1056=item C<syslog> or C<syslog=>I<expr>
1016 1057
1017Configured the context to log to syslog. If I<expr> is given, then it is 1058Configures 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: 1059evaluated in the L<Sys::Syslog> package, so you could use:
1019 1060
1020 log=syslog=LOG_LOCAL0 1061 log=syslog=LOG_LOCAL0
1021 1062
1022=item C<nolog> 1063=item C<nolog>
… …
1064 filter=warn 1105 filter=warn
1065 1106
1066 # or, more verbose 1107 # or, more verbose
1067 filter=only,level,warn 1108 filter=only,level,warn
1068 1109
1069=item C<1>..C<9>, a logging level name (C<error>, C<debug> etc.) 1110=item C<1>..C<9> or a logging level name (C<error>, C<debug> etc.)
1070 1111
1071A numeric loglevel or the name of a loglevel will be interpreted according 1112A 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, 1113to the most recent C<only>, C<except> or C<level> directive. By default,
1073specifying a logging level enables that and any higher priority messages. 1114specifying a logging level enables that and any higher priority messages.
1074 1115
1075=item C<+>I<context> 1116=item C<+>I<context>
1076 1117
1077Adds/attaches the named context as slave to the context. 1118Attaches the named context as slave to the context.
1078 1119
1079=item C<+> 1120=item C<+>
1080 1121
1081A line C<+> clears the slave list form the context. Anonymous (C<%name>) 1122A line C<+> detaches all contexts, i.e. clears the slave list from the
1082contexts have no slaves by default, but package contexts have the parent 1123context. Anonymous (C<%name>) contexts have no attached slaves by default,
1083context as slave by default. 1124but package contexts have the parent context as slave by default.
1084 1125
1085Example: log messages from My::Module to a file, do not send them to the 1126Example: log messages from My::Module to a file, do not send them to the
1086default log collector. 1127default log collector.
1087 1128
1088 My::Module=+,file=/tmp/mymodulelog 1129 My::Module=+,file=/tmp/mymodulelog
1089 1130
1090=back 1131=back
1091 1132
1092Any character can be escaped by prefixing it with a C<\> (backslash), as 1133Any 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 1134usual, so to log to a file containing a comma, colon, backslash and some
1094filename, you would do this: 1135spaces in the filename, you would do this:
1095 1136
1096 PERL_ANYEVENT_LOG='log=file=/some\ \:file\ with\,\ \\-escapes' 1137 PERL_ANYEVENT_LOG='log=file=/some\ \:file\ with\,\ \\-escapes'
1097 1138
1098Since whitespace (which includes newlines) is allowed, it is fine to 1139Since whitespace (which includes newlines) is allowed, it is fine to
1099specify multiple lines in C<PERL_ANYEVENT_LOG>, e.g.: 1140specify multiple lines in C<PERL_ANYEVENT_LOG>, e.g.:
… …
1133 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) { 1174 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
1134 for ("$1") { 1175 for ("$1") {
1135 if ($_ eq "stderr" ) { $ctx->log_to_warn; 1176 if ($_ eq "stderr" ) { $ctx->log_to_warn;
1136 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1"); 1177 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
1137 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1"); 1178 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
1138 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog (eval "package Sys::Syslog; $1"); 1179 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ($1);
1139 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef); 1180 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
1140 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1")); 1181 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
1141 } elsif ($_ eq "+" ) { $ctx->slaves; 1182 } elsif ($_ eq "+" ) { $ctx->slaves;
1142 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0); 1183 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
1143 } elsif ($_ eq "all" ) { $ctx->level ("all"); 1184 } elsif ($_ eq "all" ) { $ctx->level ("all");

Diff Legend

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