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.41 by root, Thu Sep 1 04:07:18 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
… …
81 8 debug 87 8 debug
82 9 trace 88 9 trace
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.
88 94
89You can normally only log a single message at highest priority level 95You 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 96(C<1>, C<fatal>), because logging a fatal message will also quit the
91program - so use it sparingly :) 97program - so use it sparingly :)
92 98
… …
108 114
109use Carp (); 115use Carp ();
110use POSIX (); 116use POSIX ();
111 117
112use AnyEvent (); BEGIN { AnyEvent::common_sense } 118use AnyEvent (); BEGIN { AnyEvent::common_sense }
113use AnyEvent::Util (); 119#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
114 120
115our $VERSION = $AnyEvent::VERSION; 121our $VERSION = $AnyEvent::VERSION;
116 122
117our ($COLLECT, $FILTER, $LOG); 123our ($COLLECT, $FILTER, $LOG);
118 124
… …
148=item AnyEvent::Log::log $level, $msg[, @args] 154=item AnyEvent::Log::log $level, $msg[, @args]
149 155
150Requests logging of the given C<$msg> with the given log level, and 156Requests logging of the given C<$msg> with the given log level, and
151returns true if the message was logged I<somewhere>. 157returns true if the message was logged I<somewhere>.
152 158
153For C<fatal> log levels, the program will abort. 159For loglevel C<fatal>, the program will abort.
154 160
155If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the 161If 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. 162C<$msg> is interpreted as an sprintf format string.
157 163
158The C<$msg> should not end with C<\n>, but may if that is convenient for 164The C<$msg> should not end with C<\n>, but may if that is convenient for
… …
203 info => 7, 209 info => 7,
204 debug => 8, 210 debug => 8,
205 trace => 9, 211 trace => 9,
206); 212);
207 213
208sub now () { time } 214our $TIME_EXACT;
215
216sub exact_time($) {
217 $TIME_EXACT = shift;
218 *_ts = $AnyEvent::MODEL
219 ? $TIME_EXACT ? \&AE::now : \&AE::time
220 : sub () { $TIME_EXACT ? do { require Time::HiRes; Time::HiRes::time () } : time };
221}
222
223BEGIN {
224 exact_time 0;
225}
209 226
210AnyEvent::post_detect { 227AnyEvent::post_detect {
211 *now = \&AE::now; 228 exact_time $TIME_EXACT;
212}; 229};
213 230
214our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); 231our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
215 232
216# time, ctx, level, msg 233# time, ctx, level, msg
… …
249 # now get raw message, unless we have it already 266 # now get raw message, unless we have it already
250 unless ($now) { 267 unless ($now) {
251 $format = $format->() if ref $format; 268 $format = $format->() if ref $format;
252 $format = sprintf $format, @args if @args; 269 $format = sprintf $format, @args if @args;
253 $format =~ s/\n$//; 270 $format =~ s/\n$//;
254 $now = now; 271 $now = _ts;
255 }; 272 };
256 273
257 # format msg 274 # format msg
258 my $str = $ctx->[4] 275 my $str = $ctx->[4]
259 ? $ctx->[4]($now, $_[0], $level, $format) 276 ? $ctx->[4]($now, $_[0], $level, $format)
… …
354 371
355 $LOGGER{$logger+0} = $logger; 372 $LOGGER{$logger+0} = $logger;
356 373
357 _reassess $logger+0; 374 _reassess $logger+0;
358 375
376 require AnyEvent::Util;
359 my $guard = AnyEvent::Util::guard { 377 my $guard = AnyEvent::Util::guard (sub {
360 # "clean up" 378 # "clean up"
361 delete $LOGGER{$logger+0}; 379 delete $LOGGER{$logger+0};
362 }; 380 });
363 381
364 sub { 382 sub {
365 $guard if 0; # keep guard alive, but don't cause runtime overhead 383 $guard if 0; # keep guard alive, but don't cause runtime overhead
366 384
367 _log $ctx, $level, @_ 385 _log $ctx, $level, @_
… …
372sub logger($;$) { 390sub logger($;$) {
373 _logger 391 _logger
374 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0], 392 $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
375 @_ 393 @_
376} 394}
395
396=item AnyEvent::Log::exact_time $on
397
398By default, C<AnyEvent::Log> will use C<AE::now>, i.e. the cached
399eventloop time, for the log timestamps. After calling this function with a
400true value it will instead resort to C<AE::time>, i.e. fetch the current
401time on each log message. This only makes a difference for event loops
402that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
403
404This setting can be changed at any time by calling this function.
405
406Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been
407initialised, this switch will also decide whether to use C<CORE::time> or
408C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
409available.
377 410
378=back 411=back
379 412
380=head1 LOGGING CONTEXTS 413=head1 LOGGING CONTEXTS
381 414
… …
513 } 546 }
514 547
515 @$_ = ($_->[0], (1 << 10) - 1 - 1) 548 @$_ = ($_->[0], (1 << 10) - 1 - 1)
516 for $LOG, $FILTER, $COLLECT; 549 for $LOG, $FILTER, $COLLECT;
517 550
518 $LOG->slaves; 551 #$LOG->slaves;
519 $LOG->title ('$AnyEvent::Log::LOG'); 552 $LOG->title ('$AnyEvent::Log::LOG');
520 $LOG->log_to_warn; 553 $LOG->log_to_warn;
521 554
522 $FILTER->slaves ($LOG); 555 $FILTER->slaves ($LOG);
523 $FILTER->title ('$AnyEvent::Log::FILTER'); 556 $FILTER->title ('$AnyEvent::Log::FILTER');
… …
834 867
835Needless(?) to say, if you do not want to be bitten by some evil person 868Needless(?) 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 869calling C<chdir>, the path should be absolute. Doesn't help with
837C<chroot>, but hey... 870C<chroot>, but hey...
838 871
839=item $ctx->log_to_syslog ([$log_flags]) 872=item $ctx->log_to_syslog ([$facility])
840 873
841Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and all 874Logs 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 875all 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> 876used 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. 877facility is C<user>.
845 878
846Note that this function also sets a C<fmt_cb> - the logging part requires 879Note that this function also sets a C<fmt_cb> - the logging part requires
847an array reference with [$level, $str] as input. 880an array reference with [$level, $str] as input.
848 881
849=cut 882=cut
… …
892 0 925 0
893 }); 926 });
894} 927}
895 928
896sub log_to_syslog { 929sub log_to_syslog {
897 my ($ctx, $flags) = @_; 930 my ($ctx, $facility) = @_;
898 931
899 require Sys::Syslog; 932 require Sys::Syslog;
900 933
901 $ctx->fmt_cb (sub { 934 $ctx->fmt_cb (sub {
902 my $str = $_[3]; 935 my $str = $_[3];
903 $str =~ s/\n(?=.)/\n+ /g; 936 $str =~ s/\n(?=.)/\n+ /g;
904 937
905 [$_[2], "($_[1][0]) $str"] 938 [$_[2], "($_[1][0]) $str"]
906 }); 939 });
907 940
941 $facility ||= "user";
942
908 $ctx->log_cb (sub { 943 $ctx->log_cb (sub {
909 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8; 944 my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
910 945
911 Sys::Syslog::syslog ($flags | ($lvl - 1), $_) 946 Sys::Syslog::syslog ("$facility|" . ($lvl - 1), $_)
912 for split /\n/, $_[0][1]; 947 for split /\n/, $_[0][1];
913 948
914 0 949 0
915 }); 950 });
916} 951}
… …
1012Configures the context to log to a file with the given path. Works like 1047Configures the context to log to a file with the given path. Works like
1013C<log_to_path>. 1048C<log_to_path>.
1014 1049
1015=item C<syslog> or C<syslog=>I<expr> 1050=item C<syslog> or C<syslog=>I<expr>
1016 1051
1017Configured the context to log to syslog. If I<expr> is given, then it is 1052Configures 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: 1053evaluated in the L<Sys::Syslog> package, so you could use:
1019 1054
1020 log=syslog=LOG_LOCAL0 1055 log=syslog=LOG_LOCAL0
1021 1056
1022=item C<nolog> 1057=item C<nolog>
… …
1064 filter=warn 1099 filter=warn
1065 1100
1066 # or, more verbose 1101 # or, more verbose
1067 filter=only,level,warn 1102 filter=only,level,warn
1068 1103
1069=item C<1>..C<9>, a logging level name (C<error>, C<debug> etc.) 1104=item C<1>..C<9> or a logging level name (C<error>, C<debug> etc.)
1070 1105
1071A numeric loglevel or the name of a loglevel will be interpreted according 1106A 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, 1107to the most recent C<only>, C<except> or C<level> directive. By default,
1073specifying a logging level enables that and any higher priority messages. 1108specifying a logging level enables that and any higher priority messages.
1074 1109
1075=item C<+>I<context> 1110=item C<+>I<context>
1076 1111
1077Adds/attaches the named context as slave to the context. 1112Attaches the named context as slave to the context.
1078 1113
1079=item C<+> 1114=item C<+>
1080 1115
1081A line C<+> clears the slave list form the context. Anonymous (C<%name>) 1116A 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 1117context. Anonymous (C<%name>) contexts have no attached slaves by default,
1083context as slave by default. 1118but package contexts have the parent context as slave by default.
1084 1119
1085Example: log messages from My::Module to a file, do not send them to the 1120Example: log messages from My::Module to a file, do not send them to the
1086default log collector. 1121default log collector.
1087 1122
1088 My::Module=+,file=/tmp/mymodulelog 1123 My::Module=+,file=/tmp/mymodulelog
1089 1124
1090=back 1125=back
1091 1126
1092Any character can be escaped by prefixing it with a C<\> (backslash), as 1127Any 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 1128usual, so to log to a file containing a comma, colon, backslash and some
1094filename, you would do this: 1129spaces in the filename, you would do this:
1095 1130
1096 PERL_ANYEVENT_LOG='log=file=/some\ \:file\ with\,\ \\-escapes' 1131 PERL_ANYEVENT_LOG='log=file=/some\ \:file\ with\,\ \\-escapes'
1097 1132
1098Since whitespace (which includes newlines) is allowed, it is fine to 1133Since whitespace (which includes newlines) is allowed, it is fine to
1099specify multiple lines in C<PERL_ANYEVENT_LOG>, e.g.: 1134specify multiple lines in C<PERL_ANYEVENT_LOG>, e.g.:
… …
1133 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) { 1168 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
1134 for ("$1") { 1169 for ("$1") {
1135 if ($_ eq "stderr" ) { $ctx->log_to_warn; 1170 if ($_ eq "stderr" ) { $ctx->log_to_warn;
1136 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1"); 1171 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
1137 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1"); 1172 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
1138 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog (eval "package Sys::Syslog; $1"); 1173 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ($1);
1139 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef); 1174 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
1140 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1")); 1175 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
1141 } elsif ($_ eq "+" ) { $ctx->slaves; 1176 } elsif ($_ eq "+" ) { $ctx->slaves;
1142 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0); 1177 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
1143 } elsif ($_ eq "all" ) { $ctx->level ("all"); 1178 } elsif ($_ eq "all" ) { $ctx->level ("all");

Diff Legend

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