jacques has asked for the wisdom of the Perl Monks concerning the following question:

In my script, I am logging errors (warnings and dies) to a log file. I want every message in the log to be preceded by a timestamp. So this is what I have come up with: 
open (STDERR, '>>', $log_file) or die "Can't write to $log_file: $!";

die log_error ("This error will have a timestamp.");

sub log_error {
return  "@{[scalar(localtime(time))]}: $_[0]";
}

[download]
The problem with this approach is that if my script unexpectingly dies or there is warning that I didn't anticipate (for example, the use of an unintialized variable or a bare word), the error message will appear in the log file, but without a timestamp. How can I make everything written to the log automatically have a timestamp?

Replies are listed 'Best First'.
Re: Using STDERR and timestamps to write to a log file
by merlyn (Sage) on Apr 27, 2005 at 17:11 UTC
[reply]
      Thanks. I need to start searching your columns instead of perlmonks. :)
[reply]
[reply]
[d/l]
Re: Using STDERR and timestamps to write to a log file
by deibyz (Hermit) on Apr 27, 2005 at 17:12 UTC
    I think you could set callbacks for $SIG{__DIE__} and $SIG{__WARN__}. Something in the lines of (untested):

    $SIG{__DIE__}  = sub {die  log_error(shift) };#changed $_->shift
$SIG{__WARN__} = sub {warn log_error(shift) };

    [download]

    Edited: Changed $_ to shift

[reply]
[d/l]
[select]
Re: Using STDERR and timestamps to write to a log file
by sir.shz (Novice) on Apr 27, 2005 at 17:24 UTC
    How about Log::Log4perl? adding/removing timestamp is just a matter of changing the formatting pattern in the configuration file.
[reply]
Re: Using STDERR and timestamps to write to a log file
by Zaxo (Archbishop) on Apr 27, 2005 at 17:24 UTC

    You can have a $SIG{__DIE__) handler add the timestamp, 

    local $SIG{__DIE__} = sub {
    my $msg = localtime() . ' ' . shift;
    die $msg;
};

    [download]

    After Compline,
    Zaxo

[reply]
[d/l]
Re: Using STDERR and timestamps to write to a log file
by davido (Cardinal) on Apr 27, 2005 at 17:16 UTC

    How about tieing the STDERR filehandle to a class that automatically datestamps all of its output? My untested hope is that this would still play nice with Carp. ...just a thought.


    Dave

[reply]
Re: Using STDERR and timestamps to write to a log file
by salva (Canon) on Apr 27, 2005 at 17:38 UTC
    an alternative aproach is to pipe STDERR through another command/process that timestamps every line. You will loose some precission, but it would work for any output, even if it's genetated from some XS module.

    You can also do further processing of the output easily. For example, the code below copies STDERR to some file while adding a timestamp and removing ANSI color escape sequences from the data. 

    $0=~m|([^/]*)$|;
my $name=$1;
our $filename="/tmp/debug-$name.out";

my $pid=open STDERR, "|-";
if (defined $pid and $pid==0) {
  print "writing output to $filename\n";
  open (TEE,">$filename");
  select TEE; $|=1;
  print TEE "$0 started at ".`date`."\n";
  select STDERR;
  my $ESC=quotemeta "\033[";
  while(<STDIN>) {
    my $line=$_;
    my ($sec, $min, $hour)=gmtime;
    print STDERR $line;
    $line=~s|$ESC.*?m||go;
    printf TEE "%02d:%02d:%02d| %s",$hour,$min,$sec,$line;
  }
  exit(0);
}

    [download]
[reply]
[d/l]
Re: Using STDERR and timestamps to write to a log file
by r34d0nl1 (Pilgrim) on Apr 27, 2005 at 18:27 UTC
    just a consideration: take care with the amount of log the application is going to generate.
    In the past we had some applications that were generating logs and after a while
    because the applications were in a factory with hundreds of users we ran out of space in the unix server.
    So, don't forget to create something to check a max filesize or something like this. See ya;
[reply]
      You may also use an external tool like "logrotate" to take care of the logfile.
[reply]
Re: Using STDERR and timestamps to write to a log file
by Booger (Pilgrim) on Apr 27, 2005 at 17:30 UTC

    Yet another example for you... (not that you need another, though)

    I do the following for one of my mod_perl apps in which I use warn to output debugging & status information to Apaches error_log: 

    $SIG{__WARN__} = sub {
    $msg = undef;
    foreach (@_) { 
        $msg =~ s/ at.*$// unless $msg =~ /(uninit|deprec)/; 
    } 
    print STDERR 'MyApp...' . $msg;
}

    [download]
    Where I really only want to see the line number if it's an uninitialized or deprecated warning message. One could very easily add a timestamp to this, too.
[reply]
[d/l]
Re: Using STDERR and timestamps to write to a log file
by ww (Archbishop) on Apr 27, 2005 at 17:19 UTC
    and, at least the specific instances of problems you "didn't anticipate" can be greatly reduced by...

            all in chorus now....

                "use strict; use warnings; (or -w in the shebang)!"

[reply]

Back to Seekers of Perl Wisdom