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.43 by root, Mon Sep 5 07:21:54 2011 UTC vs.
Revision 1.72 by root, Wed Feb 9 00:28:21 2022 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 fatal => "No config found, cannot continue!"; # never returns
12 AE::log warn => "it's a bit too hot"; 12 AE::log alert => "The battery died!";
13 AE::log error => "the flag was false!"; 13 AE::log crit => "The battery is too hot!";
14 AE::log fatal => "the bit toggled! run!"; # never returns 14 AE::log error => "Division by zero attempted.";
15 AE::log warn => "Couldn't delete the file.";
16 AE::log note => "Attempted to create config, but config already exists.";
17 AE::log info => "File soandso successfully deleted.";
18 AE::log debug => "the function returned 3";
19 AE::log trace => "going to call function abc";
15 20
16 # available log levels in order: 21Log level overview:
17 # fatal alert critical error warn note info debug trace
18
19"Complex" uses (for speed sensitive code):
20
21 use AnyEvent::Log;
22
23 my $tracer = AnyEvent::Log::logger trace => \$my $trace;
24
25 $tracer->("i am here") if $trace;
26 $tracer->(sub { "lots of data: " . Dumper $self }) if $trace;
27
28Configuration (also look at the EXAMPLES section):
29
30 # set logging for the current package to errors and higher only
31 AnyEvent::Log::ctx->level ("error");
32
33 # set logging level to suppress anything below "notice"
34 $AnyEvent::Log::FILTER->level ("notice");
35
36 # send all critical and higher priority messages to syslog,
37 # regardless of (most) other settings
38 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
39 level => "critical",
40 log_to_syslog => "user",
41 );
42
43=head1 DESCRIPTION
44
45This module implements a relatively simple "logging framework". It doesn't
46attempt to be "the" logging solution or even "a" logging solution for
47AnyEvent - AnyEvent simply creates logging messages internally, and this
48module more or less exposes the mechanism, with some extra spiff to allow
49using it from other modules as well.
50
51Remember that the default verbosity level is C<0> (C<off>), so nothing
52will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number
53before starting your program, or change the logging level at runtime with
54something like:
55
56 use AnyEvent::Log;
57 $AnyEvent::Log::FILTER->level ("info");
58
59The design goal behind this module was to keep it simple (and small),
60but make it powerful enough to be potentially useful for any module, and
61extensive enough for the most common tasks, such as logging to multiple
62targets, or being able to log into a database.
63
64The module is also usable before AnyEvent itself is initialised, in which
65case some of the functionality might be reduced.
66
67The amount of documentation might indicate otherwise, but the runtime part
68of the module is still just below 300 lines of code.
69
70=head1 LOGGING LEVELS
71
72Logging levels in this module range from C<1> (highest priority) to C<9>
73(lowest priority). Note that the lowest numerical value is the highest
74priority, so when this document says "higher priority" it means "lower
75numerical value".
76
77Instead of specifying levels by name you can also specify them by aliases:
78 22
79 LVL NAME SYSLOG PERL NOTE 23 LVL NAME SYSLOG PERL NOTE
80 1 fatal emerg exit system unusable, aborts program! 24 1 fatal emerg exit system unusable, aborts program!
81 2 alert failure in primary system 25 2 alert failure in primary system
82 3 critical crit failure in backup system 26 3 critical crit failure in backup system
… …
85 6 note notice unusual conditions 29 6 note notice unusual conditions
86 7 info normal messages, no action required 30 7 info normal messages, no action required
87 8 debug debugging messages for development 31 8 debug debugging messages for development
88 9 trace copious tracing output 32 9 trace copious tracing output
89 33
34"Complex" uses (for speed sensitive code, e.g. trace/debug messages):
35
36 use AnyEvent::Log;
37
38 my $tracer = AnyEvent::Log::logger trace => \my $trace;
39
40 $tracer->("i am here") if $trace;
41 $tracer->(sub { "lots of data: " . Dumper $self }) if $trace;
42
43Configuration (also look at the EXAMPLES section):
44
45 # set default logging level to suppress anything below "notice"
46 # i.e. enable logging at "notice" or above - the default is to
47 # to not log anything at all.
48 $AnyEvent::Log::FILTER->level ("notice");
49
50 # set logging for the current package to errors and higher only
51 AnyEvent::Log::ctx->level ("error");
52
53 # enable logging for the current package, regardless of global logging level
54 AnyEvent::Log::ctx->attach ($AnyEvent::Log::LOG);
55
56 # enable debug logging for module some::mod and enable logging by default
57 (AnyEvent::Log::ctx "some::mod")->level ("debug");
58 (AnyEvent::Log::ctx "some::mod")->attach ($AnyEvent::Log::LOG);
59
60 # send all critical and higher priority messages to syslog,
61 # regardless of (most) other settings
62 $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
63 level => "critical",
64 log_to_syslog => "user",
65 );
66
67=head1 DESCRIPTION
68
69This module implements a relatively simple "logging framework". It doesn't
70attempt to be "the" logging solution or even "a" logging solution for
71AnyEvent - AnyEvent simply creates logging messages internally, and this
72module more or less exposes the mechanism, with some extra spiff to allow
73using it from other modules as well.
74
75Remember that the default verbosity level is C<4> (C<error>), so only
76errors and more important messages will be logged, unless you set
77C<PERL_ANYEVENT_VERBOSE> to a higher number before starting your program
78(C<AE_VERBOSE=5> is recommended during development), or change the logging
79level at runtime with something like:
80
81 use AnyEvent::Log;
82 $AnyEvent::Log::FILTER->level ("info");
83
84The design goal behind this module was to keep it simple (and small),
85but make it powerful enough to be potentially useful for any module,
86and extensive enough for the most common tasks, such as logging to
87multiple targets, or being able to log into a database.
88
89The module is also usable before AnyEvent itself is initialised, in which
90case some of the functionality might be reduced.
91
92The amount of documentation might indicate otherwise, but the runtime part
93of the module is still just below 300 lines of code.
94
95=head1 LOGGING LEVELS
96
97Logging levels in this module range from C<1> (highest priority) to C<9>
98(lowest priority). Note that the lowest numerical value is the highest
99priority, so when this document says "higher priority" it means "lower
100numerical value".
101
102Instead of specifying levels by name you can also specify them by aliases:
103
104 LVL NAME SYSLOG PERL NOTE
105 1 fatal emerg exit system unusable, aborts program!
106 2 alert failure in primary system
107 3 critical crit failure in backup system
108 4 error err die non-urgent program errors, a bug
109 5 warn warning possible problem, not necessarily error
110 6 note notice unusual conditions
111 7 info normal messages, no action required
112 8 debug debugging messages for development
113 9 trace copious tracing output
114
90As you can see, some logging levels have multiple aliases - the first one 115As you can see, some logging levels have multiple aliases - the first one
91is the "official" name, the second one the "syslog" name (if it differs) 116is the "official" name, the second one the "syslog" name (if it differs)
92and the third one the "perl" name, suggesting (only!) that you log C<die> 117and the third one the "perl" name, suggesting (only!) that you log C<die>
93messages at C<error> priority. The NOTE column tries to provide some 118messages at C<error> priority. The NOTE column tries to provide some
94rationale on how to chose a logging level. 119rationale on how to chose a logging level.
95 120
96As a rough guideline, levels 1..3 are primarily meant for users of 121As a rough guideline, levels 1..3 are primarily meant for users of the
97the program (admins, staff), and are the only logged to STDERR by 122program (admins, staff), and are the only ones logged to STDERR by
98default. Levels 4..6 are meant for users and developers alike, while 123default. Levels 4..6 are meant for users and developers alike, while
99levels 7..9 are usually meant for developers. 124levels 7..9 are usually meant for developers.
100 125
101You can normally only log a single message at highest priority level 126You can normally only log a message once at highest priority level (C<1>,
102(C<1>, C<fatal>), because logging a fatal message will also quit the 127C<fatal>), because logging a fatal message will also quit the program - so
103program - so use it sparingly :) 128use it sparingly :)
129
130For example, a program that finds an unknown switch on the commandline
131might well use a fatal logging level to tell users about it - the "system"
132in this case would be the program, or module.
104 133
105Some methods also offer some extra levels, such as C<0>, C<off>, C<none> 134Some methods also offer some extra levels, such as C<0>, C<off>, C<none>
106or C<all> - these are only valid in the methods they are documented for. 135or C<all> - these are only valid for the methods that document them.
107 136
108=head1 LOGGING FUNCTIONS 137=head1 LOGGING FUNCTIONS
109 138
110These functions allow you to log messages. They always use the caller's 139The following functions allow you to log messages. They always use the
111package as a "logging context". Also, the main logging function C<log> is 140caller's package as a "logging context". Also, the main logging function,
112callable as C<AnyEvent::log> or C<AE::log> when the C<AnyEvent> module is 141C<log>, is aliased to C<AnyEvent::log> and C<AE::log> when the C<AnyEvent>
113loaded. 142module is loaded.
114 143
115=over 4 144=over 4
116 145
117=cut 146=cut
118 147
119package AnyEvent::Log; 148package AnyEvent::Log;
120 149
121use Carp (); 150use Carp ();
122use POSIX (); 151use POSIX ();
123 152
153# layout of a context
154# 0 1 2 3 4, 5
155# [$title, $level, %$slaves, &$logcb, &$fmtcb, $cap]
156
124use AnyEvent (); BEGIN { AnyEvent::common_sense } 157use AnyEvent (); BEGIN { AnyEvent::common_sense }
125#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log 158#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
126 159
127our $VERSION = $AnyEvent::VERSION; 160our $VERSION = $AnyEvent::VERSION;
128 161
129our ($COLLECT, $FILTER, $LOG); 162our ($COLLECT, $FILTER, $LOG);
130 163
131our ($now_int, $now_str1, $now_str2); 164our ($now_int, $now_str1, $now_str2);
132 165
133# Format Time, not public - yet? 166# Format Time, not public - yet?
134sub ft($) { 167sub format_time($) {
135 my $i = int $_[0]; 168 my $i = int $_[0];
136 my $f = sprintf "%06d", 1e6 * ($_[0] - $i); 169 my $f = sprintf "%06d", 1e6 * ($_[0] - $i);
137 170
138 ($now_int, $now_str1, $now_str2) = ($i, split /\x01/, POSIX::strftime "%Y-%m-%d %H:%M:%S.\x01 %z", localtime $i) 171 ($now_int, $now_str1, $now_str2) = ($i, split /\x01/, POSIX::strftime "%Y-%m-%d %H:%M:%S.\x01 %z", localtime $i)
139 if $now_int != $i; 172 if $now_int != $i;
… …
172 205
173Last not least, C<$msg> might be a code reference, in which case it is 206Last not least, C<$msg> might be a code reference, in which case it is
174supposed to return the message. It will be called only then the message 207supposed to return the message. It will be called only then the message
175actually gets logged, which is useful if it is costly to create the 208actually gets logged, which is useful if it is costly to create the
176message in the first place. 209message in the first place.
210
211This function takes care of saving and restoring C<$!> and C<$@>, so you
212don't have to.
177 213
178Whether the given message will be logged depends on the maximum log level 214Whether the given message will be logged depends on the maximum log level
179and the caller's package. The return value can be used to ensure that 215and the caller's package. The return value can be used to ensure that
180messages or not "lost" - for example, when L<AnyEvent::Debug> detects a 216messages or not "lost" - for example, when L<AnyEvent::Debug> detects a
181runtime error it tries to log it at C<die> level, but if that message is 217runtime error it tries to log it at C<die> level, but if that message is
… …
235}; 271};
236 272
237our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); 273our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
238 274
239# time, ctx, level, msg 275# time, ctx, level, msg
240sub _format($$$$) { 276sub default_format($$$$) {
241 my $ts = ft $_[0]; 277 my $ts = format_time $_[0];
242 my $ct = " "; 278 my $ct = " ";
243 279
244 my @res; 280 my @res;
245 281
246 for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) { 282 for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) {
… …
262 ? $level+0 298 ? $level+0
263 : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught"; 299 : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught";
264 300
265 my $mask = 1 << $level; 301 my $mask = 1 << $level;
266 302
267 my ($success, %seen, @ctx, $now, $fmt); 303 my ($success, %seen, @ctx, $now, @fmt);
268 304
269 do 305 do
270 { 306 {
271 # skip if masked 307 # if !ref, then it's a level number
308 if (!ref $ctx) {
309 $level = $ctx;
272 if ($ctx->[1] & $mask && !$seen{$ctx+0}++) { 310 } elsif ($ctx->[1] & $mask and !$seen{$ctx+0}++) {
311 # logging/recursing into this context
312
313 # level cap
314 if ($ctx->[5] > $level) {
315 push @ctx, $level; # restore level when going up in tree
316 $level = $ctx->[5];
317 }
318
319 # log if log cb
273 if ($ctx->[3]) { 320 if ($ctx->[3]) {
274 # logging target found 321 # logging target found
322
323 local ($!, $@);
275 324
276 # now get raw message, unless we have it already 325 # now get raw message, unless we have it already
277 unless ($now) { 326 unless ($now) {
278 $format = $format->() if ref $format; 327 $format = $format->() if ref $format;
279 $format = sprintf $format, @args if @args; 328 $format = sprintf $format, @args if @args;
… …
282 }; 331 };
283 332
284 # format msg 333 # format msg
285 my $str = $ctx->[4] 334 my $str = $ctx->[4]
286 ? $ctx->[4]($now, $_[0], $level, $format) 335 ? $ctx->[4]($now, $_[0], $level, $format)
287 : ($fmt ||= _format $now, $_[0], $level, $format); 336 : ($fmt[$level] ||= default_format $now, $_[0], $level, $format);
288 337
289 $success = 1; 338 $success = 1;
290 339
291 $ctx->[3]($str) 340 $ctx->[3]($str)
292 or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate 341 or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate
… …
409time on each log message. This only makes a difference for event loops 458time on each log message. This only makes a difference for event loops
410that actually cache the time (such as L<EV> or L<AnyEvent::Loop>). 459that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
411 460
412This setting can be changed at any time by calling this function. 461This setting can be changed at any time by calling this function.
413 462
414Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been 463Since C<AnyEvent::Log> has to work even before L<AnyEvent> has been
415initialised, this switch will also decide whether to use C<CORE::time> or 464initialised, this switch will also decide whether to use C<CORE::time> or
416C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes 465C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
417available. 466available.
467
468=item AnyEvent::Log::format_time $timestamp
469
470Formats a timestamp as returned by C<< AnyEvent->now >> or C<<
471AnyEvent->time >> or many other functions in the same way as
472C<AnyEvent::Log> does.
473
474In your main program (as opposed to in your module) you can override
475the default timestamp display format by loading this module and then
476redefining this function.
477
478Most commonly, this function can be used in formatting callbacks.
479
480=item AnyEvent::Log::default_format $time, $ctx, $level, $msg
481
482Format a log message using the given timestamp, logging context, log level
483and log message.
484
485This is the formatting function used to format messages when no custom
486function is provided.
487
488In your main program (as opposed to in your module) you can override the
489default message format by loading this module and then redefining this
490function.
491
492=item AnyEvent::Log::fatal_exit()
493
494This is the function that is called after logging a C<fatal> log
495message. It must not return.
496
497The default implementation simply calls C<exit 1>.
498
499In your main program (as opposed to in your module) you can override
500the fatal exit function by loading this module and then redefining this
501function. Make sure you don't return.
418 502
419=back 503=back
420 504
421=head1 LOGGING CONTEXTS 505=head1 LOGGING CONTEXTS
422 506
… …
510 594
511=item $ctx = AnyEvent::Log::ctx [$pkg] 595=item $ctx = AnyEvent::Log::ctx [$pkg]
512 596
513This function creates or returns a logging context (which is an object). 597This function creates or returns a logging context (which is an object).
514 598
515If a package name is given, then the context for that packlage is 599If a package name is given, then the context for that package is
516returned. If it is called without any arguments, then the context for the 600returned. If it is called without any arguments, then the context for the
517callers package is returned (i.e. the same context as a C<AE::log> call 601callers package is returned (i.e. the same context as a C<AE::log> call
518would use). 602would use).
519 603
520If C<undef> is given, then it creates a new anonymous context that is not 604If C<undef> is given, then it creates a new anonymous context that is not
… …
596package AnyEvent::Log::COLLECT; 680package AnyEvent::Log::COLLECT;
597package AE::Log::COLLECT; 681package AE::Log::COLLECT;
598 682
599package AnyEvent::Log::Ctx; 683package AnyEvent::Log::Ctx;
600 684
601# 0 1 2 3 4
602# [$title, $level, %$slaves, &$logcb, &$fmtcb]
603
604=item $ctx = new AnyEvent::Log::Ctx methodname => param... 685=item $ctx = new AnyEvent::Log::Ctx methodname => param...
605 686
606This is a convenience constructor that makes it simpler to construct 687This is a convenience constructor that makes it simpler to construct
607anonymous logging contexts. 688anonymous logging contexts.
608 689
… …
695 776
696=item $ctx->disable ($level[, $level...]) 777=item $ctx->disable ($level[, $level...])
697 778
698Disables logging for the given levels, leaving all others unchanged. 779Disables logging for the given levels, leaving all others unchanged.
699 780
781=item $ctx->cap ($level)
782
783Caps the maximum priority to the given level, for all messages logged
784to, or passing through, this context. That is, while this doesn't affect
785whether a message is logged or passed on, the maximum priority of messages
786will be limited to the specified level - messages with a higher priority
787will be set to the specified priority.
788
789Another way to view this is that C<< ->level >> filters out messages with
790a too low priority, while C<< ->cap >> modifies messages with a too high
791priority.
792
793This is useful when different log targets have different interpretations
794of priority. For example, for a specific command line program, a wrong
795command line switch might well result in a C<fatal> log message, while the
796same message, logged to syslog, is likely I<not> fatal to the system or
797syslog facility as a whole, but more likely a mere C<error>.
798
799This can be modeled by having a stderr logger that logs messages "as-is"
800and a syslog logger that logs messages with a level cap of, say, C<error>,
801or, for truly system-critical components, actually C<critical>.
802
700=cut 803=cut
701 804
702sub _lvl_lst { 805sub _lvl_lst {
703 map { 806 map {
704 $_ > 0 && $_ <= 9 ? $_+0 807 $_ > 0 && $_ <= 9 ? $_+0
705 : $_ eq "all" ? (1 .. 9) 808 : $_ eq "all" ? (1 .. 9)
706 : $STR2LEVEL{$_} || Carp::croak "$_: not a valid logging level, caught" 809 : $STR2LEVEL{$_} || Carp::croak "$_: not a valid logging level, caught"
707 } @_ 810 } @_
708} 811}
709 812
813sub _lvl {
814 $_[0] =~ /^(?:0|off|none)$/ ? 0 : (_lvl_lst $_[0])[-1]
815}
816
710our $NOP_CB = sub { 0 }; 817our $NOP_CB = sub { 0 };
711 818
712sub levels { 819sub levels {
713 my $ctx = shift; 820 my $ctx = shift;
714 $ctx->[1] = 0; 821 $ctx->[1] = 0;
… …
717 AnyEvent::Log::_reassess; 824 AnyEvent::Log::_reassess;
718} 825}
719 826
720sub level { 827sub level {
721 my $ctx = shift; 828 my $ctx = shift;
722 my $lvl = $_[0] =~ /^(?:0|off|none)$/ ? 0 : (_lvl_lst $_[0])[-1];
723
724 $ctx->[1] = ((1 << $lvl) - 1) << 1; 829 $ctx->[1] = ((1 << &_lvl) - 1) << 1;
725 AnyEvent::Log::_reassess; 830 AnyEvent::Log::_reassess;
726} 831}
727 832
728sub enable { 833sub enable {
729 my $ctx = shift; 834 my $ctx = shift;
… …
737 $ctx->[1] &= ~(1 << $_) 842 $ctx->[1] &= ~(1 << $_)
738 for &_lvl_lst; 843 for &_lvl_lst;
739 AnyEvent::Log::_reassess; 844 AnyEvent::Log::_reassess;
740} 845}
741 846
847sub cap {
848 my $ctx = shift;
849 $ctx->[5] = &_lvl;
850}
851
742=back 852=back
743 853
744=head3 SLAVE CONTEXTS 854=head3 SLAVE CONTEXTS
745 855
746The following methods attach and detach another logging context to a 856The following methods attach and detach another logging context to a
… …
774sub attach { 884sub attach {
775 my $ctx = shift; 885 my $ctx = shift;
776 886
777 $ctx->[2]{$_+0} = $_ 887 $ctx->[2]{$_+0} = $_
778 for map { AnyEvent::Log::ctx $_ } @_; 888 for map { AnyEvent::Log::ctx $_ } @_;
889 AnyEvent::Log::_reassess;
779} 890}
780 891
781sub detach { 892sub detach {
782 my $ctx = shift; 893 my $ctx = shift;
783 894
784 delete $ctx->[2]{$_+0} 895 delete $ctx->[2]{$_+0}
785 for map { AnyEvent::Log::ctx $_ } @_; 896 for map { AnyEvent::Log::ctx $_ } @_;
897 AnyEvent::Log::_reassess;
786} 898}
787 899
788sub slaves { 900sub slaves {
789 undef $_[0][2]; 901 undef $_[0][2];
790 &attach; 902 &attach;
903 AnyEvent::Log::_reassess;
791} 904}
792 905
793=back 906=back
794 907
795=head3 LOG TARGETS 908=head3 LOG TARGETS
… …
798the logging (which consists of formatting the message and printing it or 911the logging (which consists of formatting the message and printing it or
799whatever it wants to do with it). 912whatever it wants to do with it).
800 913
801=over 4 914=over 4
802 915
803=item $ctx->log_cb ($cb->($str) 916=item $ctx->log_cb ($cb->($str))
804 917
805Replaces the logging callback on the context (C<undef> disables the 918Replaces the logging callback on the context (C<undef> disables the
806logging callback). 919logging callback).
807 920
808The logging callback is responsible for handling formatted log messages 921The logging callback is responsible for handling formatted log messages
… …
833 946
834Replaces the formatting callback on the context (C<undef> restores the 947Replaces the formatting callback on the context (C<undef> restores the
835default formatter). 948default formatter).
836 949
837The callback is passed the (possibly fractional) timestamp, the original 950The callback is passed the (possibly fractional) timestamp, the original
838logging context, the (numeric) logging level and the raw message string 951logging context (object, not title), the (numeric) logging level and
839and needs to return a formatted log message. In most cases this will be a 952the raw message string and needs to return a formatted log message. In
840string, but it could just as well be an array reference that just stores 953most cases this will be a string, but it could just as well be an array
841the values. 954reference that just stores the values.
842 955
843If, for some reason, you want to use C<caller> to find out more baout the 956If, for some reason, you want to use C<caller> to find out more about the
844logger then you should walk up the call stack until you are no longer 957logger then you should walk up the call stack until you are no longer
845inside the C<AnyEvent::Log> package. 958inside the C<AnyEvent::Log> package.
846 959
960To implement your own logging callback, you might find the
961C<AnyEvent::Log::format_time> and C<AnyEvent::Log::default_format>
962functions useful.
963
964Example: format the message just as AnyEvent::Log would, by letting
965AnyEvent::Log do the work. This is a good basis to design a formatting
966callback that only changes minor aspects of the formatting.
967
968 $ctx->fmt_cb (sub {
969 my ($time, $ctx, $lvl, $msg) = @_;
970
971 AnyEvent::Log::default_format $time, $ctx, $lvl, $msg
972 });
973
847Example: format just the raw message, with numeric log level in angle 974Example: format just the raw message, with numeric log level in angle
848brackets. 975brackets.
849 976
850 $ctx->fmt_cb (sub { 977 $ctx->fmt_cb (sub {
851 my ($time, $ctx, $lvl, $msg) = @_; 978 my ($time, $ctx, $lvl, $msg) = @_;
852 979
853 "<$lvl>$msg\n" 980 "<$lvl>$msg\n"
854 }); 981 });
855 982
856Example: return an array reference with just the log values, and use 983Example: return an array reference with just the log values, and use
857C<PApp::SQL::sql_exec> to store the emssage in a database. 984C<PApp::SQL::sql_exec> to store the message in a database.
858 985
859 $ctx->fmt_cb (sub { \@_ }); 986 $ctx->fmt_cb (sub { \@_ });
860 $ctx->log_cb (sub { 987 $ctx->log_cb (sub {
861 my ($msg) = @_; 988 my ($msg) = @_;
862 989
… …
874Sets the C<log_cb> to simply use C<CORE::warn> to report any messages 1001Sets the C<log_cb> to simply use C<CORE::warn> to report any messages
875(usually this logs to STDERR). 1002(usually this logs to STDERR).
876 1003
877=item $ctx->log_to_file ($path) 1004=item $ctx->log_to_file ($path)
878 1005
879Sets the C<log_cb> to log to a file (by appending), unbuffered. 1006Sets the C<log_cb> to log to a file (by appending), unbuffered. The
1007function might return before the log file has been opened or created.
880 1008
881=item $ctx->log_to_path ($path) 1009=item $ctx->log_to_path ($path)
882 1010
883Same as C<< ->log_to_file >>, but opens the file for each message. This 1011Same as C<< ->log_to_file >>, but opens the file for each message. This
884is much slower, but allows you to change/move/rename/delete the file at 1012is much slower, but allows you to change/move/rename/delete the file at
… …
919 warn shift; 1047 warn shift;
920 0 1048 0
921 }); 1049 });
922} 1050}
923 1051
1052# this function is a good example of why threads are a must,
1053# simply for priority inversion.
1054sub _log_to_disk {
1055 # eval'uating this at runtime saves 220kb rss - perl has become
1056 # an insane memory waster.
1057 eval q{ # poor man's autoloading {}
1058 sub _log_to_disk {
1059 my ($ctx, $path, $keepopen) = @_;
1060
1061 my $fh;
1062 my @queue;
1063 my $delay;
1064 my $disable;
1065
1066 use AnyEvent::IO ();
1067
1068 my $kick = sub {
1069 undef $delay;
1070 return unless @queue;
1071 $delay = 1;
1072
1073 # we pass $kick to $kick, so $kick itself doesn't keep a reference to $kick.
1074 my $kick = shift;
1075
1076 # write one or more messages
1077 my $write = sub {
1078 # we write as many messages as have been queued
1079 my $data = join "", @queue;
1080 @queue = ();
1081
1082 AnyEvent::IO::aio_write $fh, $data, sub {
1083 $disable = 1;
1084 @_
1085 ? ($_[0] == length $data or AE::log 4 => "unable to write to logfile '$path': short write")
1086 : AE::log 4 => "unable to write to logfile '$path': $!";
1087 undef $disable;
1088
1089 if ($keepopen) {
1090 $kick->($kick);
1091 } else {
1092 AnyEvent::IO::aio_close ($fh, sub {
1093 undef $fh;
1094 $kick->($kick);
1095 });
1096 }
1097 };
1098 };
1099
1100 if ($fh) {
1101 $write->();
1102 } else {
1103 AnyEvent::IO::aio_open
1104 $path,
1105 AnyEvent::IO::O_CREAT | AnyEvent::IO::O_WRONLY | AnyEvent::IO::O_APPEND,
1106 0666,
1107 sub {
1108 $fh = shift
1109 or do {
1110 $disable = 1;
1111 AE::log 4 => "unable to open logfile '$path': $!";
1112 undef $disable;
1113 return;
1114 };
1115
1116 $write->();
1117 }
1118 ;
1119 }
1120 };
1121
1122 $ctx->log_cb (sub {
1123 return if $disable;
1124 push @queue, shift;
1125 $kick->($kick) unless $delay;
1126 0
1127 });
1128
1129 $kick->($kick) if $keepopen; # initial open
1130 };
1131 };
1132 die if $@;
1133 &_log_to_disk
1134}
1135
924sub log_to_file { 1136sub log_to_file {
925 my ($ctx, $path) = @_; 1137 my ($ctx, $path) = @_;
926 1138
927 open my $fh, ">>", $path 1139 _log_to_disk $ctx, $path, 1;
928 or die "$path: $!";
929
930 $ctx->log_cb (sub {
931 syswrite $fh, shift;
932 0
933 });
934} 1140}
935 1141
936sub log_to_path { 1142sub log_to_path {
937 my ($ctx, $path) = @_; 1143 my ($ctx, $path) = @_;
938 1144
939 $ctx->log_cb (sub { 1145 _log_to_disk $ctx, $path, 0;
940 open my $fh, ">>", $path
941 or die "$path: $!";
942
943 syswrite $fh, shift;
944 0
945 });
946} 1146}
947 1147
948sub log_to_syslog { 1148sub log_to_syslog {
949 my ($ctx, $facility) = @_; 1149 my ($ctx, $facility) = @_;
950 1150
… …
979=over 4 1179=over 4
980 1180
981=item $ctx->log ($level, $msg[, @params]) 1181=item $ctx->log ($level, $msg[, @params])
982 1182
983Same as C<AnyEvent::Log::log>, but uses the given context as log context. 1183Same as C<AnyEvent::Log::log>, but uses the given context as log context.
1184
1185Example: log a message in the context of another package.
1186
1187 (AnyEvent::Log::ctx "Other::Package")->log (warn => "heely bo");
984 1188
985=item $logger = $ctx->logger ($level[, \$enabled]) 1189=item $logger = $ctx->logger ($level[, \$enabled])
986 1190
987Same as C<AnyEvent::Log::logger>, but uses the given context as log 1191Same as C<AnyEvent::Log::logger>, but uses the given context as log
988context. 1192context.
… …
1036 1240
1037Context names starting with a C<%> are anonymous contexts created when the 1241Context names starting with a C<%> are anonymous contexts created when the
1038name is first mentioned. The difference to package contexts is that by 1242name is first mentioned. The difference to package contexts is that by
1039default they have no attached slaves. 1243default they have no attached slaves.
1040 1244
1245This makes it possible to create new log contexts that can be refered to
1246multiple times by name within the same log specification.
1247
1041=item a perl package name 1248=item a perl package name
1042 1249
1043Any other string references the logging context associated with the given 1250Any other string references the logging context associated with the given
1044Perl C<package>. In the unlikely case where you want to specify a package 1251Perl C<package>. In the unlikely case where you want to specify a package
1045context that matches on of the other context name forms, you can add a 1252context that matches on of the other context name forms, you can add a
… …
1076=item C<nolog> 1283=item C<nolog>
1077 1284
1078Configures the context to not log anything by itself, which is the 1285Configures the context to not log anything by itself, which is the
1079default. Same as C<< $ctx->log_cb (undef) >>. 1286default. Same as C<< $ctx->log_cb (undef) >>.
1080 1287
1288=item C<cap=>I<level>
1289
1290Caps logging messages entering this context at the given level, i.e.
1291reduces the priority of messages with higher priority than this level. The
1292default is C<0> (or C<off>), meaning the priority will not be touched.
1293
1081=item C<0> or C<off> 1294=item C<0> or C<off>
1082 1295
1083Sets the logging level of the context ot C<0>, i.e. all messages will be 1296Sets the logging level of the context to C<0>, i.e. all messages will be
1084filtered out. 1297filtered out.
1085 1298
1086=item C<all> 1299=item C<all>
1087 1300
1088Enables all logging levels, i.e. filtering will effectively be switched 1301Enables all logging levels, i.e. filtering will effectively be switched
… …
1130 1343
1131Attaches the named context as slave to the context. 1344Attaches the named context as slave to the context.
1132 1345
1133=item C<+> 1346=item C<+>
1134 1347
1135A line C<+> detaches all contexts, i.e. clears the slave list from the 1348A lone C<+> detaches all contexts, i.e. clears the slave list from the
1136context. Anonymous (C<%name>) contexts have no attached slaves by default, 1349context. Anonymous (C<%name>) contexts have no attached slaves by default,
1137but package contexts have the parent context as slave by default. 1350but package contexts have the parent context as slave by default.
1138 1351
1139Example: log messages from My::Module to a file, do not send them to the 1352Example: log messages from My::Module to a file, do not send them to the
1140default log collector. 1353default log collector.
… …
1171 1384
1172 my $pkg = sub { 1385 my $pkg = sub {
1173 $_[0] eq "log" ? $LOG 1386 $_[0] eq "log" ? $LOG
1174 : $_[0] eq "filter" ? $FILTER 1387 : $_[0] eq "filter" ? $FILTER
1175 : $_[0] eq "collect" ? $COLLECT 1388 : $_[0] eq "collect" ? $COLLECT
1176 : $_[0] =~ /^%(.+)$/ ? ($anon{$1} ||= ctx undef) 1389 : $_[0] =~ /^%(.+)$/ ? ($anon{$1} ||= do { my $ctx = ctx undef; $ctx->[0] = $_[0]; $ctx })
1177 : $_[0] =~ /^(.*?)(?:::)?$/ ? ctx "$1" # egad :/ 1390 : $_[0] =~ /^(.*?)(?:::)?$/ ? ctx "$1" # egad :/
1178 : die # never reached? 1391 : die # never reached?
1179 }; 1392 };
1180 1393
1181 /\G[[:space:]]+/gc; # skip initial whitespace 1394 /\G[[:space:]]+/gc; # skip initial whitespace
… …
1187 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) { 1400 while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
1188 for ("$1") { 1401 for ("$1") {
1189 if ($_ eq "stderr" ) { $ctx->log_to_warn; 1402 if ($_ eq "stderr" ) { $ctx->log_to_warn;
1190 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1"); 1403 } elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
1191 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1"); 1404 } elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
1192 } elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ($1); 1405 } elsif (/^syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ("$1");
1193 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef); 1406 } elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
1407 } elsif (/^cap=(.+)/ ) { $ctx->cap ("$1");
1194 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1")); 1408 } elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
1195 } elsif ($_ eq "+" ) { $ctx->slaves; 1409 } elsif ($_ eq "+" ) { $ctx->slaves;
1196 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0); 1410 } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
1197 } elsif ($_ eq "all" ) { $ctx->level ("all"); 1411 } elsif ($_ eq "all" ) { $ctx->level ("all");
1198 } elsif ($_ eq "level" ) { $ctx->level ("all"); $level = "level"; 1412 } elsif ($_ eq "level" ) { $ctx->level ("all"); $level = "level";
… …
1215 if (/\G(.+)/g) { 1429 if (/\G(.+)/g) {
1216 die "PERL_ANYEVENT_LOG ($spec): parse error at '$1'\n"; 1430 die "PERL_ANYEVENT_LOG ($spec): parse error at '$1'\n";
1217 } 1431 }
1218} 1432}
1219 1433
12201;
1221
1222=head1 EXAMPLES 1434=head1 EXAMPLES
1223 1435
1224This section shows some common configurations, both as code, and as 1436This section shows some common configurations, both as code, and as
1225C<PERL_ANYEVENT_LOG> string. 1437C<PERL_ANYEVENT_LOG> string.
1226 1438
… …
1266 1478
1267 PERL_ANYEVENT_LOG=%filelogger=file=/some/path:collect=+%filelogger 1479 PERL_ANYEVENT_LOG=%filelogger=file=/some/path:collect=+%filelogger
1268 1480
1269In both cases, messages are still written to STDERR. 1481In both cases, messages are still written to STDERR.
1270 1482
1483=item Additionally log all messages with C<warn> and higher priority to
1484C<syslog>, but cap at C<error>.
1485
1486This logs all messages to the default log target, but also logs messages
1487with priority C<warn> or higher (and not filtered otherwise) to syslog
1488facility C<user>. Messages with priority higher than C<error> will be
1489logged with level C<error>.
1490
1491 $AnyEvent::Log::LOG->attach (
1492 new AnyEvent::Log::Ctx
1493 level => "warn",
1494 cap => "error",
1495 syslog => "user",
1496 );
1497
1498 PERL_ANYEVENT_LOG=log=+%syslog:%syslog=warn,cap=error,syslog
1499
1271=item Write trace messages (only) from L<AnyEvent::Debug> to the default logging target(s). 1500=item Write trace messages (only) from L<AnyEvent::Debug> to the default logging target(s).
1272 1501
1273Attach the C<$AnyEvent::Log::LOG> context to the C<AnyEvent::Debug> 1502Attach the C<$AnyEvent::Log::LOG> context to the C<AnyEvent::Debug>
1274context - this simply circumvents the global filtering for trace messages. 1503context - this simply circumvents the global filtering for trace messages.
1275 1504
… …
1282assumes the log level for AnyEvent::Debug hasn't been changed from the 1511assumes the log level for AnyEvent::Debug hasn't been changed from the
1283default. 1512default.
1284 1513
1285=back 1514=back
1286 1515
1516=head1 ASYNCHRONOUS DISK I/O
1517
1518This module uses L<AnyEvent::IO> to actually write log messages (in
1519C<log_to_file> and C<log_to_path>), so it doesn't block your program when
1520the disk is busy and a non-blocking L<AnyEvent::IO> backend is available.
1521
1287=head1 AUTHOR 1522=head1 AUTHOR
1288 1523
1289 Marc Lehmann <schmorp@schmorp.de> 1524 Marc Lehmann <schmorp@schmorp.de>
1290 http://home.schmorp.de/ 1525 http://anyevent.schmorp.de
1291 1526
1292=cut 1527=cut
1293 1528
15291
1530

Diff Legend

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