Sep 06

It seems as if every CPAN module has its own way of logging debug information and error conditions. For example:

  • LWP – activate by use’ing LWP::Debug; outputs to STDERR
  • DBI – activate by calling DBI->trace(); outputs to STDERR or a file
  • Rose::DB – activate by setting various $Debug package variables; outputs to STDERR
  • Encode::* – activate by modifying various DEBUG subroutines to return 1; outputs using warn()
  • Apache::* – activate by setting the Apache log level and restarting; outputs to the Apache logs

In addition, there must be CPAN modules that have interesting things to say but choose not to log at all, because they don’t want to invent another logging mechanism or become dependent on an existing one.

This situation is pretty much the opposite of what I want when developing a large application. I want a single way to turn logging on and off, and to control where logs get sent, for all of the modules I’m using.

This being Perl, there are many fine logging frameworks available: Log::Log4perl, Log::Dispatch, Log::Handler, Log::Agent, Log::Trivial, etc. So why do CPAN modules eschew the use of these and invent their own mechanisms that are almost guaranteed to be less powerful?

  • The very existence of so many logging modules means that there is no one standard that a CPAN author would feel comfortable binding their users to. As usual, TMTOWTDI is a double-edged sword.
  • A logging framework can be a significant dependency for a module to have, easily dwarfing the size of the module itself. For small modules that want to minimize dependencies, depending on Log4perl (for example) is a non-starter.

A Common Log API

One thing to notice is that while the logging frameworks all differ in their configuration and activation API, and the set of features they support, the API to log messages is generally quite simple. At its core it consists of

  • A set of valid log levels, e.g. debug, info, warn, error, fatal
  • Methods to log a message at a particular level, e.g. $log->debug()
  • Methods to determine if a particular level is activated, e.g. $log->is_debug()

I expect most CPAN modules would happily stick to this API, and let the application worry about configuring what’s getting logged and where it’s going. Therefore…

Proposed Module: Log::Any

I propose a small module called Log::Any that provides this API, with no dependencies and no logging implementation of its own. Log::Any would be designed to be linked by the main application to an existing logging framework.

A CPAN module would use it like this:

    package Foo;
    use Log::Any;
    my $log = Log::Any->get_logger(category => __PACKAGE__);

    $log->error("an error occurred");

    $log->debug("arguments are: " . Dumper(@_))
        if $log->is_debug();

By default, methods like $log->debug would be no-ops, and methods like $log->is_debug() would return false.

As a convenient shorthand, you can use

    package Foo;
    use Log::Any qw($log);

to create the logger, which is equivalent to the first example except that $log is (necessarily) a package-scoped rather than lexical variable.

For efficiency, we also provide dynamic variables in place of is_debug etc.:

    package Foo;
    use Log::Any qw($log $log_is_debug);

    $log->debug("arguments are: " . Dumper(@_)) if $log_is_debug;

How does an application activate logging? The low-level way is to call Log::Any->set_logger (better name pending) with either a logger object, or a subroutine that takes a log category and returns a logger object.

For example, to link with Log::Log4perl:

    use Log::Any;
    use Log::Log4perl;

    Log::Log4perl->init("log.conf");
    Log::Any->set_logger
       (sub { Log::Log4perl->get_logger(@_) });

To link with Log::Dispatch, with all categories going to the screen:

    use Log::Any;
    use Log::Dispatch;

    my $dispatcher = Log::Dispatch::Screen->new(...);
    Log::Any->set_logger($dispatcher);

To link with Log::Dispatch, with different categories going to different dispatchers:

    use Log::Any;
    use Log::Dispatch;

    my $dispatcher_screen = Log::Dispatch::Screen->new(...);
    my $dispatcher_file   = Log::Dispatch::File->new(...);

    sub choose_dispatcher {
        my $category = shift;
        $category =~ /DBI|LWP/ ? $dispatcher_file : $dispatcher_screen;
    }
    Log::Any->set_logger(&choose_dispatcher);

This API is a little awkward for the average user. One solution is for logging frameworks themselves to provide more convenient mixins, e.g.:

   use Log::Dispatch;   # this also defines Log::Any::use_log_dispatch
   my $d = Log::Dispatch::File->new(...);
   Log::Any->use_log_dispatch($d);  # calls set_logger for you

   use Log::Log4perl;   # this also defines Log::Any::use_log4perl
   Log::Any->use_log4perl();        # calls set_logger for you

set_logger would be implemented so as to take effect on all existing as well as future loggers. Any $log objects already created inside modules will automatically be switched when set_logger is called. (i.e. $log will probably be a thin proxy object.) This means that Log::Any need not be initialized by the time it is used in CPAN modules, and it allows set_logger to be called more than once per application.

Promoting Use

For Log::Any to be useful, a substantial number of modules – especially major modules – would have to adopt its use. Fortunately, with its minimal footprint and standalone nature, authors should not find Log::Any a difficult dependency to add. Existing logging mechanisms, such as LWP::Debug and $DBI::tfh, could easily be converted to write *both* to their existing output streams and to Log::Any. This would preserve backward compatibility for existing applications, but allow new applications to benefit from more powerful logging. I would be willing to submit such patches to major module authors to get things going.

Feedback welcome. Thanks!

(See original use.perl posting with comments)

Leave a Reply

preload preload preload