[ViewVC] Diff of: cvs/AnyEvent/lib/AnyEvent/Log.pm

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.39 by root, Fri Aug 26 00:37:26 2011 UTC vs.
Revision 1.48 by root, Thu Mar 22 00:19:39 2012 UTC

 Simple uses:
    use AnyEvent;
-   AE::log debug => "hit my knee";
+   AE::log trace => "going to call function abc";
-   AE::log warn  => "it's a bit too hot";
+   AE::log debug => "the function returned 3";
-   AE::log error => "the flag was false!";
+   AE::log info  => "file soandso successfully deleted";
-   AE::log fatal => "the bit toggled! run!"; # never returns
+   AE::log note  => "wanted to create config, but config was already created";
+   AE::log warn  => "couldn't delete the file";
+   AE::log error => "failed to retrieve data";
+   AE::log crit  => "the battery temperature is too hot";
+   AE::log alert => "the battery died";
+   AE::log fatal => "no config found, cannot continue"; # never returns
+Log level overview:
+   LVL NAME      SYSLOG   PERL  NOTE
+    1  fatal     emerg    exit  system unusable, aborts program!
+    2  alert                    failure in primary system
+    3  critical  crit           failure in backup system
+    4  error     err      die   non-urgent program errors, a bug
+    5  warn      warning        possible problem, not necessarily error
+    6  note      notice         unusual conditions
+    7  info                     normal messages, no action required
+    8  debug                    debugging messages for development
+    9  trace                    copious tracing output
-"Complex" uses (for speed sensitive code):
+"Complex" uses (for speed sensitive code, e.g. trace/debug messages):
    use AnyEvent::Log;
    my $tracer = AnyEvent::Log::logger trace => \$my $trace;
    # send all critical and higher priority messages to syslog,
    # regardless of (most) other settings
    $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
       level         => "critical",
-      log_to_syslog => 0,
+      log_to_syslog => "user",
    );
 =head1 DESCRIPTION
 This module implements a relatively simple "logging framework". It doesn't
 attempt to be "the" logging solution or even "a" logging solution for
 AnyEvent - AnyEvent simply creates logging messages internally, and this
 module more or less exposes the mechanism, with some extra spiff to allow
 using it from other modules as well.
-Remember that the default verbosity level is C<0> (C<off>), so nothing
+Remember that the default verbosity level is C<3> (C<critical>), so little
 will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number
 before starting your program, or change the logging level at runtime with
 something like:
    use AnyEvent::Log;
 numerical value".
 Instead of specifying levels by name you can also specify them by aliases:
    LVL NAME      SYSLOG   PERL  NOTE
-   1   fatal     emerg    exit  aborts program!
+    1  fatal     emerg    exit  system unusable, aborts program!
-   2   alert
+    2  alert                    failure in primary system
-   3   critical  crit
+    3  critical  crit           failure in backup system
-   4   error     err      die
+    4  error     err      die   non-urgent program errors, a bug
-   5   warn      warning
+    5  warn      warning        possible problem, not necessarily error
-   6   note      notice
+    6  note      notice         unusual conditions
-   7   info
+    7  info                     normal messages, no action required
-   8   debug
+    8  debug                    debugging messages for development
-   9   trace
+    9  trace                    copious tracing output
 As you can see, some logging levels have multiple aliases - the first one
 is the "official" name, the second one the "syslog" name (if it differs)
-and the third one the "perl" name, suggesting that you log C<die> messages
+and the third one the "perl" name, suggesting (only!) that you log C<die>
-at C<error> priority.
+messages at C<error> priority. The NOTE column tries to provide some
+rationale on how to chose a logging level.
+As a rough guideline, levels 1..3 are primarily meant for users of the
+program (admins, staff), and are the only ones logged to STDERR by
+default. Levels 4..6 are meant for users and developers alike, while
+levels 7..9 are usually meant for developers.
-You can normally only log a single message at highest priority level
+You can normally only log a message once at highest priority level (C<1>,
-(C<1>, C<fatal>), because logging a fatal message will also quit the
+C<fatal>), because logging a fatal message will also quit the program - so
-program - so use it sparingly :)
+use it sparingly :)
 Some methods also offer some extra levels, such as C<0>, C<off>, C<none>
-or C<all> - these are only valid in the methods they are documented for.
+or C<all> - these are only valid for the methods that documented them.
 =head1 LOGGING FUNCTIONS
-These functions allow you to log messages. They always use the caller's
+The following functions allow you to log messages. They always use the
-package as a "logging context". Also, the main logging function C<log> is
+caller's package as a "logging context". Also, the main logging function,
-callable as C<AnyEvent::log> or C<AE::log> when the C<AnyEvent> module is
+C<log>, is aliased to C<AnyEvent::log> and C<AE::log> when the C<AnyEvent>
-loaded.
+module is loaded.
 =over 4
 =cut
 package AnyEvent::Log;
 use Carp ();
 use POSIX ();
+# layout of a context
+#       0       1         2        3        4,    5
+# [$title, $level, %$slaves, &$logcb, &$fmtcb, $cap]
 use AnyEvent (); BEGIN { AnyEvent::common_sense }
 #use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
 our $VERSION = $AnyEvent::VERSION;
 =item AnyEvent::Log::log $level, $msg[, @args]
 Requests logging of the given C<$msg> with the given log level, and
 returns true if the message was logged I<somewhere>.
-For C<fatal> log levels, the program will abort.
+For loglevel C<fatal>, the program will abort.
 If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the
 C<$msg> is interpreted as an sprintf format string.
 The C<$msg> should not end with C<\n>, but may if that is convenient for
 Last not least, C<$msg> might be a code reference, in which case it is
 supposed to return the message. It will be called only then the message
 actually gets logged, which is useful if it is costly to create the
 message in the first place.
+This function takes care of saving and restoring C<$!> and C<$@>, so you
+don't have to.
 Whether the given message will be logged depends on the maximum log level
 and the caller's package. The return value can be used to ensure that
 messages or not "lost" - for example, when L<AnyEvent::Debug> detects a
 runtime error it tries to log it at C<die> level, but if that message is
    }
    join "", @res
 }
+sub fatal_exit() {
+   exit 1;
+}
 sub _log {
    my ($ctx, $level, $format, @args) = @_;
    $level = $level > 0 && $level <= 9
             ? $level+0
             : $STR2LEVEL{$level} || Carp::croak "$level: not a valid logging level, caught";
    my $mask = 1 << $level;
-   my ($success, %seen, @ctx, $now, $fmt);
+   my ($success, %seen, @ctx, $now, @fmt);
    do
       {
-         # skip if masked
+         # if !ref, then it's a level number
+         if (!ref $ctx) {
+            $level = $ctx;
-         if ($ctx->[1] & $mask && !$seen{$ctx+0}++) {
+         } elsif ($ctx->[1] & $mask and !$seen{$ctx+0}++) {
+            # logging/recursing into this context
+            # level cap
+            if ($ctx->[5] > $level) {
+               push @ctx, $level; # restore level when going up in tree
+               $level = $ctx->[5];
+            }
+            # log if log cb
             if ($ctx->[3]) {
                # logging target found
+               local ($!, $@);
                # now get raw message, unless we have it already
                unless ($now) {
                   $format = $format->() if ref $format;
                   $format = sprintf $format, @args if @args;
                };
                # format msg
                my $str = $ctx->[4]
                   ? $ctx->[4]($now, $_[0], $level, $format)
-                  : ($fmt ||= _format $now, $_[0], $level, $format);
+                  : ($fmt[$level] ||= _format $now, $_[0], $level, $format);
                $success = 1;
                $ctx->[3]($str)
                   or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate
             }
          }
       }
    while $ctx = pop @ctx;
-   exit 1 if $level <= 1;
+   fatal_exit if $level <= 1;
    $success
 }
 sub log($$;@) {
    _log
       $CTX{ (caller)[0] } ||= _pkg_ctx +(caller)[0],
       @_;
 }
-*AnyEvent::log = *AE::log = \&log;
 =item $logger = AnyEvent::Log::logger $level[, \$enabled]
 Creates a code reference that, when called, acts as if the
 C<AnyEvent::Log::log> function was called at this point with the given
 level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with
    $LOGGER{$logger+0} = $logger;
    _reassess $logger+0;
-   require AnyEvent::Util;
+   require AnyEvent::Util unless $AnyEvent::Util::VERSION;
    my $guard = AnyEvent::Util::guard (sub {
       # "clean up"
       delete $LOGGER{$logger+0};
    });
 This can be used to implement config-file (re-)loading: before loading a
 configuration, reset all contexts.
 =cut
+our $ORIG_VERBOSE = $AnyEvent::VERBOSE;
+$AnyEvent::VERBOSE = 9;
 sub reset {
    # hard to kill complex data structures
    # we "recreate" all package loggers and reset the hierarchy
    while (my ($k, $v) = each %CTX) {
       @$v = ($k, (1 << 10) - 1 - 1, { });
    $LOG->title ('$AnyEvent::Log::LOG');
    $LOG->log_to_warn;
    $FILTER->slaves ($LOG);
    $FILTER->title ('$AnyEvent::Log::FILTER');
-   $FILTER->level ($AnyEvent::VERBOSE);
+   $FILTER->level ($ORIG_VERBOSE);
    $COLLECT->slaves ($FILTER);
    $COLLECT->title ('$AnyEvent::Log::COLLECT');
    _reassess;
 }
+# override AE::log/logger
+*AnyEvent::log    = *AE::log    = \&log;
+*AnyEvent::logger = *AE::logger = \&logger;
+# convert AnyEvent loggers to AnyEvent::Log loggers
+$_->[0] = ctx $_->[0] # convert "pkg" to "ctx"
+   for values %LOGGER;
 # create the default logger contexts
 $LOG     = ctx undef;
 $FILTER  = ctx undef;
 $COLLECT = ctx undef;
 package AnyEvent::Log::COLLECT;
 package AE::Log::COLLECT;
 package AnyEvent::Log::Ctx;
-#       0       1         2        3        4
-# [$title, $level, %$slaves, &$logcb, &$fmtcb]
 =item $ctx = new AnyEvent::Log::Ctx methodname => param...
 This is a convenience constructor that makes it simpler to construct
 anonymous logging contexts.
 =item $ctx->disable ($level[, $level...])
 Disables logging for the given levels, leaving all others unchanged.
+=item $ctx->cap ($level)
+Caps the maximum priority to the given level, for all messages logged
+to, or passing through, this context. That is, while this doesn't affect
+whether a message is logged or passed on, the maximum priority of messages
+will be limited to the specified level - messages with a higher priority
+will be set to the specified priority.
+Another way to view this is that C<< ->level >> filters out messages with
+a too low priority, while C<< ->cap >> modifies messages with a too high
+priority.
+This is useful when different log targets have different interpretations
+of priority. For example, for a specific command line program, a wrong
+command line switch might well result in a C<fatal> log message, while the
+same message, logged to syslog, is likely I<not> fatal to the system or
+syslog facility as a whole, but more likely a mere C<error>.
+This can be modeled by having a stderr logger that logs messages "as-is"
+and a syslog logger that logs messages with a level cap of, say, C<error>,
+or, for truly system-critical components, actually C<critical>.
 =cut
 sub _lvl_lst {
    map {
       $_ > 0 && $_ <= 9 ? $_+0
       : $_ eq "all"     ? (1 .. 9)
       : $STR2LEVEL{$_} || Carp::croak "$_: not a valid logging level, caught"
    } @_
 }
+sub _lvl {
+   $_[0] =~ /^(?:0|off|none)$/ ? 0 : (_lvl_lst $_[0])[-1]
+}
 our $NOP_CB = sub { 0 };
 sub levels {
    my $ctx = shift;
    $ctx->[1] = 0;
    AnyEvent::Log::_reassess;
 }
 sub level {
    my $ctx = shift;
-   my $lvl = $_[0] =~ /^(?:0|off|none)$/ ? 0 : (_lvl_lst $_[0])[-1];
-   $ctx->[1] =  ((1 << $lvl) - 1) << 1;
+   $ctx->[1] = ((1 << &_lvl) - 1) << 1;
    AnyEvent::Log::_reassess;
 }
 sub enable {
    my $ctx = shift;
    $ctx->[1] &= ~(1 << $_)
       for &_lvl_lst;
    AnyEvent::Log::_reassess;
 }
+sub cap {
+   my $ctx = shift;
+   $ctx->[5] = &_lvl;
+}
 =back
 =head3 SLAVE CONTEXTS
 The following methods attach and detach another logging context to a
 Needless(?) to say, if you do not want to be bitten by some evil person
 calling C<chdir>, the path should be absolute. Doesn't help with
 C<chroot>, but hey...
-=item $ctx->log_to_syslog ([$log_flags])
+=item $ctx->log_to_syslog ([$facility])
-Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and all
+Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and
-the others in the obvious way. If specified, then the C<$log_flags> are
+all the others in the obvious way. If specified, then the C<$facility> is
-simply or'ed onto the priority argument and can contain any C<LOG_xxx>
+used as the facility (C<user>, C<auth>, C<local0> and so on). The default
-flags valid for Sys::Syslog::syslog, except for the priority levels.
+facility is C<user>.
 Note that this function also sets a C<fmt_cb> - the logging part requires
 an array reference with [$level, $str] as input.
 =cut
       0
    });
 }
 sub log_to_syslog {
-   my ($ctx, $flags) = @_;
+   my ($ctx, $facility) = @_;
    require Sys::Syslog;
    $ctx->fmt_cb (sub {
       my $str = $_[3];
       $str =~ s/\n(?=.)/\n+ /g;
       [$_[2], "($_[1][0]) $str"]
    });
+   $facility ||= "user";
    $ctx->log_cb (sub {
       my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
-      Sys::Syslog::syslog ($flags | ($lvl - 1), $_)
+      Sys::Syslog::syslog ("$facility|" . ($lvl - 1), $_)
          for split /\n/, $_[0][1];
       0
    });
 }
 =item C<nolog>
 Configures the context to not log anything by itself, which is the
 default. Same as C<< $ctx->log_cb (undef) >>.
+=item C<cap=>I<level>
+Caps logging messages entering this context at the given level, i.e.
+reduces the priority of messages with higher priority than this level. The
+default is C<0> (or C<off>), meaning the priority will not be touched.
 =item C<0> or C<off>
-Sets the logging level of the context ot C<0>, i.e. all messages will be
+Sets the logging level of the context to C<0>, i.e. all messages will be
 filtered out.
 =item C<all>
 Enables all logging levels, i.e. filtering will effectively be switched
 Attaches the named context as slave to the context.
 =item C<+>
-A line C<+> detaches all contexts, i.e. clears the slave list from the
+A lone C<+> detaches all contexts, i.e. clears the slave list from the
 context. Anonymous (C<%name>) contexts have no attached slaves by default,
 but package contexts have the parent context as slave by default.
 Example: log messages from My::Module to a file, do not send them to the
 default log collector.
    my $pkg = sub {
       $_[0] eq "log"              ? $LOG
       : $_[0] eq "filter"         ? $FILTER
       : $_[0] eq "collect"        ? $COLLECT
-      : $_[0] =~ /^%(.+)$/        ? ($anon{$1} ||= ctx undef)
+      : $_[0] =~ /^%(.+)$/        ? ($anon{$1} ||= do { my $ctx = ctx undef; $ctx->[0] = $_[0]; $ctx })
       : $_[0] =~ /^(.*?)(?:::)?$/ ? ctx "$1" # egad :/
       : die # never reached?
    };
    /\G[[:space:]]+/gc; # skip initial whitespace
       while (/\G((?:[^,:[:space:]]+|::|\\.)+)/gc) {
          for ("$1") {
             if ($_ eq "stderr"               ) { $ctx->log_to_warn;
             } elsif (/^file=(.+)/            ) { $ctx->log_to_file ("$1");
             } elsif (/^path=(.+)/            ) { $ctx->log_to_path ("$1");
-            } elsif (/syslog(?:=(.*))?/      ) { require Sys::Syslog; $ctx->log_to_syslog (eval "package Sys::Syslog; $1");
+            } elsif (/^syslog(?:=(.*))?/     ) { require Sys::Syslog; $ctx->log_to_syslog ("$1");
             } elsif ($_ eq "nolog"           ) { $ctx->log_cb (undef);
+            } elsif (/^cap=(.+)/             ) { $ctx->cap ("$1");
             } elsif (/^\+(.+)$/              ) { $ctx->attach ($pkg->("$1"));
             } elsif ($_ eq "+"               ) { $ctx->slaves;
             } elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
             } elsif ($_ eq "all"             ) { $ctx->level ("all");
             } elsif ($_ eq "level"           ) { $ctx->level ("all"); $level = "level";
 This writes them only when the global logging level allows it, because
 it is attached to the default context which is invoked I<after> global
 filtering.
-   $AnyEvent::Log::FILTER->attach
+   $AnyEvent::Log::FILTER->attach (
       new AnyEvent::Log::Ctx log_to_file => $path);
    PERL_ANYEVENT_LOG=filter=+%filelogger:%filelogger=file=/some/path
 This writes them regardless of the global logging level, because it is
    PERL_ANYEVENT_LOG=%filelogger=file=/some/path:collect=+%filelogger
 In both cases, messages are still written to STDERR.
+=item Additionally log all messages with C<warn> and higher priority to
+C<syslog>, but cap at C<error>.
+This logs all messages to the default log target, but also logs messages
+with priority C<warn> or higher (and not filtered otherwise) to syslog
+facility C<user>. Messages with priority higher than C<error> will be
+logged with level C<error>.
+   $AnyEvent::Log::LOG->attach (
+      new AnyEvent::Log::Ctx
+         level  => "warn",
+         cap    => "error",
+         syslog => "user",
+   );
+   PERL_ANYEVENT_LOG=log=+%syslog:%syslog=warn,cap=error,syslog
 =item Write trace messages (only) from L<AnyEvent::Debug> to the default logging target(s).
 Attach the C<$AnyEvent::Log::LOG> context to the C<AnyEvent::Debug>
 context - this simply circumvents the global filtering for trace messages.

Diff Legend

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

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents): Revision 1.39 by root, Fri Aug 26 00:37:26 2011 UTC vs. Revision 1.48 by root, Thu Mar 22 00:19:39 2012 UTC

Diff Legend

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.39 by root, Fri Aug 26 00:37:26 2011 UTC vs.
Revision 1.48 by root, Thu Mar 22 00:19:39 2012 UTC