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

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.54 by root, Tue Mar 27 23:47:57 2012 UTC vs.
Revision 1.73 by root, Sun Apr 24 21:22:38 2022 UTC

    use AnyEvent;
    AE::log fatal => "No config found, cannot continue!"; # never returns
    AE::log alert => "The battery died!";
-   AE::log crit  => "The battery temperature is too hot!";
+   AE::log crit  => "The battery is too hot!";
    AE::log error => "Division by zero attempted.";
    AE::log warn  => "Couldn't delete the file.";
-   AE::log note  => "Wanted to create config, but config already exists.";
+   AE::log note  => "Attempted to create config, but config already exists.";
    AE::log info  => "File soandso successfully deleted.";
    AE::log debug => "the function returned 3";
    AE::log trace => "going to call function abc";
 Log level overview:
 "Complex" uses (for speed sensitive code, e.g. trace/debug messages):
    use AnyEvent::Log;
-   my $tracer = AnyEvent::Log::logger trace => \$my $trace;
+   my $tracer = AnyEvent::Log::logger trace => \my $trace;
    $tracer->("i am here") if $trace;
    $tracer->(sub { "lots of data: " . Dumper $self }) if $trace;
 Configuration (also look at the EXAMPLES section):
+   # set default logging level to suppress anything below "notice"
+   # i.e. enable logging at "notice" or above - the default is to
+   # to not log anything at all.
+   $AnyEvent::Log::FILTER->level ("notice");
    # set logging for the current package to errors and higher only
    AnyEvent::Log::ctx->level ("error");
-   # set logging level to suppress anything below "notice"
+   # enable logging for the current package, regardless of global logging level
-   $AnyEvent::Log::FILTER->level ("notice");
+   AnyEvent::Log::ctx->attach ($AnyEvent::Log::LOG);
+   # enable debug logging for module some::mod and enable logging by default
+   (AnyEvent::Log::ctx "some::mod")->level ("debug");
+   (AnyEvent::Log::ctx "some::mod")->attach ($AnyEvent::Log::LOG);
    # send all critical and higher priority messages to syslog,
    # regardless of (most) other settings
    $AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
       level         => "critical",
    use AnyEvent::Log;
    $AnyEvent::Log::FILTER->level ("info");
 The design goal behind this module was to keep it simple (and small),
-but make it powerful enough to be potentially useful for any module, and
+but make it powerful enough to be potentially useful for any module,
-extensive enough for the most common tasks, such as logging to multiple
+and extensive enough for the most common tasks, such as logging to
-targets, or being able to log into a database.
+multiple targets, or being able to log into a database.
 The module is also usable before AnyEvent itself is initialised, in which
 case some of the functionality might be reduced.
 The amount of documentation might indicate otherwise, but the runtime part
 For example, a program that finds an unknown switch on the commandline
 might well use a fatal logging level to tell users about it - the "system"
 in this case would be the program, or module.
 Some methods also offer some extra levels, such as C<0>, C<off>, C<none>
-or C<all> - these are only valid for the methods that documented them.
+or C<all> - these are only valid for the methods that document them.
 =head1 LOGGING FUNCTIONS
 The following functions allow you to log messages. They always use the
 caller's package as a "logging context". Also, the main logging function,
 our ($COLLECT, $FILTER, $LOG);
 our ($now_int, $now_str1, $now_str2);
 # Format Time, not public - yet?
-sub ft($) {
+sub format_time($) {
    my $i = int $_[0];
    my $f = sprintf "%06d", 1e6 * ($_[0] - $i);
    ($now_int, $now_str1, $now_str2) = ($i, split /\x01/, POSIX::strftime "%Y-%m-%d %H:%M:%S.\x01 %z", localtime $i)
       if $now_int != $i;
 };
 our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
 # time, ctx, level, msg
-sub _format($$$$) {
+sub default_format($$$$) {
-   my $ts = ft $_[0];
+   my $ts = format_time $_[0];
    my $ct = " ";
    my @res;
    for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) {
                };
                # format msg
                my $str = $ctx->[4]
                   ? $ctx->[4]($now, $_[0], $level, $format)
-                  : ($fmt[$level] ||= _format $now, $_[0], $level, $format);
+                  : ($fmt[$level] ||= default_format $now, $_[0], $level, $format);
                $success = 1;
                $ctx->[3]($str)
                   or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate
 time on each log message. This only makes a difference for event loops
 that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
 This setting can be changed at any time by calling this function.
-Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been
+Since C<AnyEvent::Log> has to work even before L<AnyEvent> has been
 initialised, this switch will also decide whether to use C<CORE::time> or
 C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
 available.
+=item AnyEvent::Log::format_time $timestamp
+Formats a timestamp as returned by C<< AnyEvent->now >> or C<<
+AnyEvent->time >> or many other functions in the same way as
+C<AnyEvent::Log> does.
+In your main program (as opposed to in your module) you can override
+the default timestamp display format by loading this module and then
+redefining this function.
+Most commonly, this function can be used in formatting callbacks.
+=item AnyEvent::Log::default_format $time, $ctx, $level, $msg
+Format a log message using the given timestamp, logging context, log level
+and log message.
+This is the formatting function used to format messages when no custom
+function is provided.
+In your main program (as opposed to in your module) you can override the
+default message format by loading this module and then redefining this
+function.
+=item AnyEvent::Log::fatal_exit()
+This is the function that is called after logging a C<fatal> log
+message. It must not return.
+The default implementation simply calls C<exit 1>.
+In your main program (as opposed to in your module) you can override
+the fatal exit function by loading this module and then redefining this
+function. Make sure you don't return.
 =back
 =head1 LOGGING CONTEXTS
 context, so it does not matter (much) if there are cycles or if the
 message can arrive at the same context via multiple paths.
 =head2 DEFAULTS
-By default, all logging contexts have an full set of log levels ("all"), a
+By default, all logging contexts have a full set of log levels ("all"), a
 disabled logging callback and the default formatting callback.
 Package contexts have the package name as logging title by default.
 They have exactly one slave - the context of the "parent" package. The
 =item $ctx = AnyEvent::Log::ctx [$pkg]
 This function creates or returns a logging context (which is an object).
-If a package name is given, then the context for that packlage is
+If a package name is given, then the context for that package is
 returned. If it is called without any arguments, then the context for the
 callers package is returned (i.e. the same context as a C<AE::log> call
 would use).
 If C<undef> is given, then it creates a new anonymous context that is not
 sub attach {
    my $ctx = shift;
    $ctx->[2]{$_+0} = $_
       for map { AnyEvent::Log::ctx $_ } @_;
+   AnyEvent::Log::_reassess;
 }
 sub detach {
    my $ctx = shift;
    delete $ctx->[2]{$_+0}
       for map { AnyEvent::Log::ctx $_ } @_;
+   AnyEvent::Log::_reassess;
 }
 sub slaves {
    undef $_[0][2];
    &attach;
+   AnyEvent::Log::_reassess;
 }
 =back
 =head3 LOG TARGETS
 the logging (which consists of formatting the message and printing it or
 whatever it wants to do with it).
 =over 4
-=item $ctx->log_cb ($cb->($str)
+=item $ctx->log_cb ($cb->($str))
 Replaces the logging callback on the context (C<undef> disables the
 logging callback).
 The logging callback is responsible for handling formatted log messages
 If, for some reason, you want to use C<caller> to find out more about the
 logger then you should walk up the call stack until you are no longer
 inside the C<AnyEvent::Log> package.
+To implement your own logging callback, you might find the
+C<AnyEvent::Log::format_time> and C<AnyEvent::Log::default_format>
+functions useful.
+Example: format the message just as AnyEvent::Log would, by letting
+AnyEvent::Log do the work. This is a good basis to design a formatting
+callback that only changes minor aspects of the formatting.
+   $ctx->fmt_cb (sub {
+      my ($time, $ctx, $lvl, $msg) = @_;
+      AnyEvent::Log::default_format $time, $ctx, $lvl, $msg
+   });
 Example: format just the raw message, with numeric log level in angle
 brackets.
    $ctx->fmt_cb (sub {
       my ($time, $ctx, $lvl, $msg) = @_;
 Sets the C<log_cb> to simply use C<CORE::warn> to report any messages
 (usually this logs to STDERR).
 =item $ctx->log_to_file ($path)
-Sets the C<log_cb> to log to a file (by appending), unbuffered.
+Sets the C<log_cb> to log to a file (by appending), unbuffered. The
+function might return before the log file has been opened or created.
 =item $ctx->log_to_path ($path)
 Same as C<< ->log_to_file >>, but opens the file for each message. This
 is much slower, but allows you to change/move/rename/delete the file at
       warn shift;
       0
    });
 }
+# this function is a good example of why threads are a must,
+# simply for priority inversion.
+sub _log_to_disk {
+   # eval'uating this at runtime saves 220kb rss - perl has become
+   # an insane memory waster.
+   eval q{ # poor man's autoloading {}
+      sub _log_to_disk {
+         my ($ctx, $path, $keepopen) = @_;
+         my $fh;
+         my @queue;
+         my $delay;
+         my $disable;
+         use AnyEvent::IO ();
+         my $kick = sub {
+            undef $delay;
+            return unless @queue;
+            $delay = 1;
+            # we pass $kick to $kick, so $kick itself doesn't keep a reference to $kick.
+            my $kick = shift;
+            # write one or more messages
+            my $write = sub {
+               # we write as many messages as have been queued
+               my $data = join "", @queue;
+               @queue = ();
+               AnyEvent::IO::aio_write $fh, $data, sub {
+                  $disable = 1;
+                  @_
+                     ? ($_[0] == length $data or AE::log 4 => "unable to write to logfile '$path': short write")
+                     :                           AE::log 4 => "unable to write to logfile '$path': $!";
+                  undef $disable;
+                  if ($keepopen) {
+                     $kick->($kick);
+                  } else {
+                     AnyEvent::IO::aio_close ($fh, sub {
+                        undef $fh;
+                        $kick->($kick);
+                     });
+                  }
+               };
+            };
+            if ($fh) {
+               $write->();
+            } else {
+               AnyEvent::IO::aio_open
+                  $path,
+                  AnyEvent::IO::O_CREAT | AnyEvent::IO::O_WRONLY | AnyEvent::IO::O_APPEND,
+                  0666,
+                  sub {
+                     $fh = shift
+                        or do {
+                           $disable = 1;
+                           AE::log 4 => "unable to open logfile '$path': $!";
+                           undef $disable;
+                           return;
+                        };
+                     $write->();
+                  }
+               ;
+            }
+         };
+         $ctx->log_cb (sub {
+            return if $disable;
+            push @queue, shift;
+            $kick->($kick) unless $delay;
+            0
+         });
+         $kick->($kick) if $keepopen; # initial open
+      };
+   };
+   die if $@;
+   &_log_to_disk
+}
 sub log_to_file {
    my ($ctx, $path) = @_;
-   open my $fh, ">>", $path
+   _log_to_disk $ctx, $path, 1;
-      or die "$path: $!";
-   $ctx->log_cb (sub {
-      syswrite $fh, shift;
-      0
-   });
 }
 sub log_to_path {
    my ($ctx, $path) = @_;
-   $ctx->log_cb (sub {
+   _log_to_disk $ctx, $path, 0;
-      open my $fh, ">>", $path
-         or die "$path: $!";
-      syswrite $fh, shift;
-      0
-   });
 }
 sub log_to_syslog {
    my ($ctx, $facility) = @_;
 =item C<%name>
 Context names starting with a C<%> are anonymous contexts created when the
 name is first mentioned. The difference to package contexts is that by
 default they have no attached slaves.
+This makes it possible to create new log contexts that can be refered to
+multiple times by name within the same log specification.
 =item a perl package name
 Any other string references the logging context associated with the given
 Perl C<package>. In the unlikely case where you want to specify a package
 assumes the log level for AnyEvent::Debug hasn't been changed from the
 default.
 =back
+=head1 ASYNCHRONOUS DISK I/O
+This module uses L<AnyEvent::IO> to actually write log messages (in
+C<log_to_file> and C<log_to_path>), so it doesn't block your program when
+the disk is busy and a non-blocking L<AnyEvent::IO> backend is available.
 =head1 AUTHOR
  Marc Lehmann <schmorp@schmorp.de>
- http://home.schmorp.de/
+ http://anyevent.schmorp.de
 =cut
 1

Diff Legend

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

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents): Revision 1.54 by root, Tue Mar 27 23:47:57 2012 UTC vs. Revision 1.73 by root, Sun Apr 24 21:22:38 2022 UTC

Diff Legend

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.54 by root, Tue Mar 27 23:47:57 2012 UTC vs.
Revision 1.73 by root, Sun Apr 24 21:22:38 2022 UTC