What's on CPAN

• 100+ Log Modules on CPAN
• Many simple logging modules
• All just slightly different
• Reimplementing same ideas, some better than others

CPAN - Domain-specific Modules

• Modules for creating/parsing specific logs, e.g.:
• Win32::EventLog
• Apache::Log, Apache::Parse::Log, Log::Common
• Sys::Syslog
• Parse::*Log, Regexp::Log::*

...but not the focus of this talk.

CPAN - Major Frameworks

• Log::Dispatch
• Log::Log4perl

Overview

• Common logging concepts
• Simple DIY logging
• Simple CPAN modules
• Complex modules

Components of Logging Systems

• Levels
  • of specific messages
  • of the running system
• Targets
• Dispatchers
• Categories

Message Levels

The importance of a message.

• log_it( "Program starting",  INFO );
• log_it( "Something's fishy", WARNING );
• log_it( "CPU on fire",       FATAL );
• log_it( Dumper(\%ENV),       DEBUG );

Message Levels - Flexible

• Can be dynamically changed in the code
• e.g.: if exception is caught, it's not FATAL anymore

•   if ($@) { 
       my $level = FATAL;
       if ($@ =~ /nuclear war averted/i) 
         { $level = WARNING; }
       log_it ( "Status: $@", $level);
    }
    

Message Levels - Granularity

• Bare minimum: FATAL, INFO, DEBUG
• Can be more additional levels, e.g.:

  WARNING

  ALERT

  MILDLY_ANNOYING

System Level

• With INFO system level
• will log: INFO and FATAL messages
• will drop DEBUG messages

Log Targets

Can be:

• files
• STDOUT, STDERR
• email, messaging, database, etc.

Also called "Output objects", "Appenders", "Sinks"

Log Dispatchers

• Objects that send messages to multiple log targets
• Could have multiple dispatcher objects in a single program

Log Categories

• Or "channels"
• Multiple dispatcher objects
• Each with a separate purpose
• E.g. logging usage statistics vs. urgent system alerts

TIMTOWTDI

Some of the differences you'll see in CPAN modules include:

Levels: Labels vs. Integers

•   log_it($error_msg, INFO)
• vs.
•   log_it($error_msg, 3)

Integers are confusing

    If the system is at logging level 4,
    and a specific log message is marked at level 3,
    should it be logged or not?

Which is it?

Rollercoaster	or	Limbo?

Arguments vs. Methods

•   log_it($error_msg, INFO)
• vs.
•   info($error_msg)

Level Granularity

• 5 Levels?
• 11 Levels?
• Unlimited?
• Expandable in the future?

Matter of taste

Objects?

•   log_error($message);
• vs.
•   $error_log->log($message);

What to do

• DIY
• Simple CPAN Modules
• Full Frameworks
  • Log::Log4perl
  • Log::Dispatch

DIY Logging

• open(ERROR_LOG, ">>app.log") 
    or die "$!";
  print ERROR_LOG "oops"; 

• Simple printing to a single target
• KISS
• Can be sufficient

2 Tricks to Know

1. Using select() to redirect print() to logs:
   
   

   select(ERROR_LOG); 
   print "oops";

   print() now goes to ERROR_LOG automatically

%SIG

2. Using signal handlers to redirect warn/die/carp to logs:
   
   

   $SIG{__WARN__} = sub { print ERROR_LOG shift ; };
   warn "oops";

   warn() now goes to ERROR_LOG automatically
   (see perldoc perlvar for %SIG)

Safe::Logs

• Prevents evil ESC codes from being written to logfiles

  • s/\x1b/[esc]/g;

• Vulnerabilities were found in xterm and PuTTY
  • http://secunia.com/advisories/8146/
• Original whitepaper from Digital Defense seems to have vanished...
• From 2003, by HD Moore (Metasploit)
• Fixed?

Tie::LogFile

• Adds formatting to each print() to a log file:
•  tie(*ERROR_LOG, 'Tie::LogFile', "test.log",
     format => '(%d) %m');
 print ERROR_LOG "test";
  
• Yields:
• (Wed Jun 7 10:56:05 2006) test

Log::LogLite

  
  my $log = new Log::LogLite("file.log", 3);

  $log->write("your error here", 1);

• Basic, simple, stable
• Uses integer levels, limbo-style
• Some formatting options via template()

Log::StdLog

  use Log::StdLog { level => 'warn', 
                    file => "error.log" };
 
  print {*STDLOG} error => "your message here\n";
  # that is the same as:
  print STDLOG ('error', "your message here\n");   

• 9 fixed named levels
• Single log target: STDLOG
• STDLOG is global, imported into each package

Others

• File::Log (some formatting magic)
• Log::Handler (8 named levels)
• Log::Trivial (sync/async writing)

Lots more, many with minimal features or poor documentation

Fancier Loggers

• More features
• Usually more than a single module
• More unusual syntax & design choices

Fancier Loggers

• Log::Message & Log::Message::Simple
      message stacks
• Log::Info
     Multiple dispatchers, called channels:
     "DEBUG", "STATS", "INFO"
• Log::Agent
     3 targets: error, output, debug (but called "channels" and not objects)
• Log::Report

Most Complete & Mature

• Log::Dispatch
• Log::Log4perl

Log::Dispatch

• Multiple log targets per dispatcher
• Log::Dispatch::* classes for specialized log targets
     e.g. DBI, email
• Easily subclassed
• Can have multiple dispatcher objects
• Also, uses 8 level labels

Log::Dispatch Example

  my $dispatcher = Log::Dispatch->new;

  
  $dispatcher->add( 
      Log::Dispatch::File->new(name => 'file1',
                               filename => 'error.log'
                               min_level => 'debug' ) );
  
  $dispatcher->log( level => 'info',
                    message => 'your error here');

Log::Log4perl

• Based on Log4J
• Incredibly adaptive
• Complexity to match
• Well documented
    e.g.: Michael Schilli's perl.com article

Log::Log4perl Features

• Different loggers per module:

    package Groceries::Food;
    my $logger = get_logger("Groceries::Food");
  

• "Groceries::Food" = a "category"
• Each category can have multiple "appenders" ( = targets)
• The appenders are Log::Dispatch::* objects

Log::Log4perl Bubbling

• Log calls bubble up to parent categories
  • If a "fatal" message is issued by the Groceries::Food logger...
  • then the Groceries logger also gets the message.
• NOTE: All parents get the log call
• No halting, as for object method dispatch
• But that "bubbling" behavior is configurable

Log::Log4perl Quirks

• Java-style configuration:

      log4perl.logger=FATAL, Screen
      log4perl.logger.Groceries.Food=DEBUG, Log
  

• Categories are not truly OO:
  • Groceries::Food is just a label to an object
  • Any module can access that with get_logger()
• "bubbling" can be tricky
• 5 levels: FATAL, ERROR, WARN, INFO, DEBUG.

Log::Channel

• Uses Log::Dispatch::* objects (targets)
• Wraps them into "channels"
• Multiple targets to a channel
• But this can be done in Log::Dispatch:
• Uses XML configuration

Unless I'm missing something, just use Log::Dispatch

Recommendations

• Simple jobs:
  • Log::LogLite
  • File::Log
  • Log::StdLog
• Complicated jobs:
  • Log::Dispatch
  • Log::Log4perl
    • if you're managing a large object heirarchy

  All IMHO, of course

Mange tak!