info  'This is an info log item'.
debug "the value of this variable is: '$this'"
[download]

# log die, warn, info, and debug events to mylog.log, but don't
# show debug events on the console.
use Log ( file=>'mylog.log', warn => 2, info => 2, debug => 1 );
[download]

package Log;

#=====================================================================
+==========
# $Id: Log.pm,v 1.8 2006-02-22 20:05:16 radmat Exp $
# Logging package for info/warn/die/debug/trace
#=====================================================================
+==========
use strict;
use warnings;
our $VERSION = sprintf "%d.%03d", q$Revision: 1.8 $ =~ /: (\d+)\.(\d+)
+/;    #CVS

#__modules__
use Fcntl;
use POSIX qw[_exit strftime];

#use subs  qw[warn die];

require Exporter;
our @ISA    = 'Exporter';
our @EXPORT = qw[info debug trace];

#__globals__
our $logfile = ( caller(0) )[0] . '.log';    # Default to main.log
our ( $debug, $trace ) = ( 0, 0 );           # No logging of debug() a
+nd trace()
our ( $info,  $warn )  = ( 1, 2 );           # Log info(), Log and pri
+nt warn()
our $seq = 0;                                # Session sequence

our $line_format = '%s %d.%04d %s';          # Line format (see POD)
our $time_format = '%Y-%m-%dT%H:%M:%S';      # POSIX strftime format
our $log_umask   = 0111;

#__subroutines__
#_____________________________________________________________________
+ import()_
sub import {

    # import - override Exporter->import
    my $me = shift;
    if ( @_ == 1 ) { $logfile = shift }
    elsif ( @_ % 2 == 0 ) {
        my %parm = @_;
        $logfile = $parm{file}   if defined $parm{file};
        $debug   = $parm{debug}  if defined $parm{debug};
        $trace   = $parm{trace}  if defined $parm{trace};
        $info    = $parm{info}   if defined $parm{info};
        $warn    = $parm{'warn'} if defined $parm{'warn'};
        
        $line_format = $parm{lineform} if defined $parm{lineform};
        $time_format = $parm{timeform} if defined $parm{timeform};
        $log_umask   = $parm{'umask'}  if defined $parm{'umask'};
    }
    else { }
    
    # TODO ? strings subs for 0/1/2
    # TODO per-package configuration
    
    umask $log_umask;
    sysopen( LOG, $logfile, O_WRONLY | O_APPEND | O_CREAT, 0777 )
      or die("Cannot log to $logfile: $!");
    select LOG;
    $| = 1;
    select STDOUT;

    $SIG{__WARN__} = sub { Log::warn(@_) };
    $SIG{__DIE__}  = sub { Log::die(@_) };

    $me->export_to_level( 1, $me, @EXPORT );
    print LOG "\n";
    info('Logging started');
}

#_____________________________________________________________________
+__ _msg()_
sub _msg {

    # _msg ( \@msgarray )
    my @a = @{ $_[0] };
    foreach (@a) {
        unless ( defined $_ ) { $_ = ''; next; }
        s/[\r\n]+/ /g;
    }
    return join( ' ', @a );
}

#_____________________________________________________________________
+__ _log()_
sub _log {

    # _log ( )
    my $time = strftime( $time_format, localtime );
    printf LOG $line_format."\n", $time, $$, $seq++, _msg( \@_ );
    }
    
#_____________________________________________________________________
+__ warn()_
sub warn ($) {

    # warn ( )
    _log( 'W:', @_ ) if $warn;
    CORE::warn(@_) if $warn == 2;
}

#_____________________________________________________________________
+___ die()_
sub die ($) {

    # die ( )
    _log( 'X:', @_ );
    CORE::die(@_);
}

#_____________________________________________________________________
+__ info()_
sub info ($) {

    # info ( )
    return undef unless $info;
    _log( 'I:', @_ );
    print STDERR _msg( \@_ ), "\n" if $info == 2;
}

#_____________________________________________________________________
+_ debug()_
sub debug ($) {

    # debug ( )
    return undef unless $debug;
    _log( 'D:', @_ );
    print STDERR '. Debug:', _msg( \@_ ), "\n" if $debug == 2;
}

#_____________________________________________________________________
+_ trace()_
sub trace ($) {

    # trace ( )
    return undef unless $trace;
    _log( 'T:', @_ );
    print STDERR '* Trace:', _msg( \@_ ), "\n" if $trace == 2;
}

1;    # modules must return a true value.

__END__
[download]

• NAME
• SYNOPSIS
• DESCRIPTION
• PRIVATE METHODS
• PUBLIC METHODS
• LOG FILE FORMAT

---

NAME

Log ($Revision: 1.9 $) - Logging package for info/warn/die/debug/trace

top

---

SYNOPSIS

    use Log;
    
    warn  'hello';
    info  'this is an information statement';
    trace 'this is a trace log item';
    debug 'this is a debug log item';
    die   'Game over, man: game over!';

top

---

DESCRIPTION

Log is a simple, lightweight logging system designed to promote logging in code by requiring a minimum of configuration, automatic logging of warn and die events, and an interface that doesn't get in the way of functional code.

When loaded, Log exports info, debug, and trace, then binds WARN and DIE events to its internal warn and die methods. These latter two end by calling CORE::warn and CORE::die, respectively, so code that depends on the default warn and die behavior will continue to work. This makes Log ideal for dropping into existing code to provide a minimal warn/die log.

Log will always record and propagate DIE events. By default, it will also record WARN events and calls to info; the WARN events will be propagated, while the info calls will be silently logged. This behavior can be altered during import: see import for more.

The default log file name is the package name of the script or module from which Log is imported, appended with '.log'. For example, a script will use a log named main.log. This can be altered during import: see import for more.

top

---

PRIVATE METHODS

import

Overrides Exporter::import, causes info, debug, and trace to be exported, and attaches global WARN and DIE signal handlers to our versions of warn and die, respectively. Also opens the log file handle and processes import parameters. This method is called during use Log.

To change default behaviors (see SYNOPSIS), parameters can be passed to import as a named-pair hash.

To specify a filename to log to, overriding the default:

    use Log ( file => 'myfile.txt' );

To change the level of verbosity for each logging type:

    use Log (
              warn  => 2,  # 2 means log and print to console
              info  => 1,  # 1 means log only
              debug => 1,
              trace => 0,  # 0 means ignore these!
            );

The verbosity of the die type cannot be altered, it is always effectively '2'. Setting warn's level to 1 will prevent warnings from propagating via CORE::warn, but will still log them; setting its value to 0 will entirely supress warnings.

Default values are ( warn=>2, info=>1, debug=>0, trace=>0 ).

To change the format of the line or time-stamp, use 'lineform' and 'timeform', respectively. See LOG FILE FORMAT for more information.

When the log file is created, a mode of 0777 is passed, mitigated by a umask of 0111, resulting in a default mode of 0666 (rw-rw-rw). This can be altered during import using the 'umask' parameter.

    use Log ( umask => 0177 );

Note that this is an octal value, not a string or decimal. See the umask documentation for more information.

_log

Responsible for writing to the log. Accepts a list of scalars, prepending them with date stamp and sequence number before writing them to the log. Before writing, scalars are passed through _msg.

_msg

Message preprocessor. Accepts a list of scalars; undefined values are converted to empty strings and all strings have line endings converted to spaces before they are joined (with a space between elements) into a single scalar, whch is returned.

top

---

PUBLIC METHODS

warn

While not exported directly, this method is bound to $SIG{__WARN__} and is responsible for recording and propagating warnings. When $warn is 1, warnings are logged only; at 0, warnings are suppressed.

Custom handlers attached to $SIG{__WARN__} should take care to call Log::warn(@_), or warnings may not be logged. If using such handlers, be sure that $warn < 2.

die

While not exported directly, this method is bound to $SIG{__DIE__} and is responsible for recording and propagating exceptions. This behavior cannot be altered.

Even exceptions caught from inside an eval block will be logged; it is a good practice to do something like:

    eval {
        sub_which_could_die();
    };
    if ($@) {
        info "Caught: $@"

        # handle the exception
    }

In this way, the log will show the exception being thrown and being caught (assuming $info > 0), making for much more sensible reading.

Custom handlers attached to $SIG{__DIE__} should take care to call Log::die(@_), or exceptions may not be logged.

info

Information statements. By default, these are logged only ($info is set to 1). Conceptually, info statements should convey important events. For example, major decisions during logical processing are prime candidates for recording via info.

The level of verbosity can be adjusted at run time via $info:

    $Log::info = 2;
    info 'This will be in the log and on the screen';
    $Log::info = 1;
    info 'This will be logged only';

This is not recommended, as it makes it very difficult to adjust these values globally via import.

Accepts a single scalar.

debug

Debug statements. By default, these are suppressed ($debug is set to 0). Conceptually, debug statements should record information that isn't important during normal conditions, but might be helpful in tracing down code or environmental problems. For example, noting states of important variables at key locations, etc.

The level of verbosity can be adjusted at run time via $debug; see info for a related example.

Accepts a single scalar.

trace

Trace statements. By default, these are suppressed ($trace is set to 0). Conceptually, trace statements should record extremely detailed operational information that is helpful in locating difficult-to-find problems. For example, entering and exiting subs, data before and after transformations, etc.

When activated it, this should be extremely verbose.

The level of verbosity can be adjusted at run time via $trace; see info for a related example.

Accepts a single scalar.

top

---

LOG FILE FORMAT

The log file format for Log is designed to be easy to parse with code, yet reasonable for a human to read as well. There is one message per line in the following format (followed by an example):

    YYYY-mm-ddTHH:MM:SS <pid>.<seq> TYPE: Message text
    2006-02-17T10:00:32 12345.0000 I: Logging started

Each time Log is imported, the logfile has a blank line appended and is issued an info event of 'Logging started' with a sequence number of 0. Dates are in ISO 8601 format without fractional seconds or timezone information.

The TYPE field is one of T, D, I, W, X; these map to trace, debug, info, warn, and die (exception) events, respectively.

The format of this line can be altered using the 'lineform' import instruction. Its value is a printf style format string for the list of values timestamp, pid, seq, message. The format will have a newline appended before use. Be certain not to use tainted user input here!

The format of the timestamp may be altered using the 'timeform' import instruction, similar to 'lineform' above; the format string will be passed to the POSIX strftime function. The warning about tainted user data above applies here as well.

Look for Log::Parser in the future.

top

---