execution log
yburge
created: 2006-05-04 15:56:27
How do you log the execution of a Perl script? I need to include all messages generated during the execution of a script, not just errors, warnings, etc.
Re: execution log
created: 2006-05-04 16:35:50
I'm making assumptions but I guess you mean that errors and warnings generated by warn or die go to STDERR whereas normal messages generated by a plain print without a filehandle go to STDOUT. On a *nix system you can run a script from the shell (Bourne, Korn, Bash) like this

script_name > output_file 2>&1

which directs STDOUT of the script into the "output_file" and also directs STDERR (file descriptor 2) into STDOUT (file descriptor 1). That way, you can get both STDOUT and STDERR into one file. I'm not sure what you would do in a MS Windows environment, perhaps other Monks can tell you (and me) what to do there.

I hope this is of use.

Cheers,

JohnGG

Re^2: execution log
created: 2006-05-04 16:59:04
That also works in Windows (except 95/98/ME, I think)
Re^2: execution log
created: 2006-05-04 19:34:42
Please excuse my ignorance (I'm just getting started with Perl, and I haven't done any programming since I was in school 25 years ago), but do I place that statement in my script? UPDATE: BTW, I'm working in Windows 2000, if that makes a difference.
Re^3: execution log
created: 2006-05-07 08:45:21
Not in the script, no. You use that syntax from the command-line to invoke the script, either in a *nix shell or from a DOS prompt, except under DOS you invoke Perl and give it your script name as the first argument. I normally use Solaris but I managed to turf the kids off the PC to try out what happens under Windows XP. I put this little script together; I called it fred

use strict;
use warnings;

print "The beginning\n";

my $flag = 1;
warn "Flag set\n" if $flag;

die "Farewell, cruel world\n";

and ran it firstly without any redirection of STDOUT or STDERR like this

C:> perl fred
The beginning
Flag set
Farewell, cruel world

C:>

I then tried redirecting STDOUT to a file

C:> perl fred > fred.out
Flag set
Farewell, cruel world

C:> type fred.out
The beginning

C:>

Finally, I tried redirecting STDERR as well

C:> perl fred > fred.out 2>&1

C:> type fred.out
The beginning
Flag set
Farewell, cruel world

C:>

Astonishingly, it seems to work just like Solaris. All they need to do now is get their slashes the right way round and we'll be laughing.

Cheers,

JohnGG

Re: execution log
created: 2006-05-04 19:42:50
yburge:

In addition to the answers you've already received, if you're on a *nix box you can also use the script or tee commands.

The script command is used to capture an entire command shell session, something1 like:

devo$ script junk.log
devo$ ls
foo   bar   baz
devo$ exit
The first script command opens a new shell where all I/O is written to junk.log in addition to the console. The exit ends the shell, and the contents of junk.log should1 be:

devo$ ls
foo   bar   baz
devo$ exit
The tee command simply copies everything going to STDOUT to the specified file, like this:

devo$ ls | tee junk.log
Here, the contents of tee would be "foo bar baz\n". Note that the STDERR would still go to wherever it normally goes. You can capture STDERR also if you do something1 like this:

devo$ (ls 2>&1) | tee junk.log
Hope this helps....

1Note: I didn't actually run this on the console of a *nix box, as my Linux box is currently down. So I faked the examples, and may have mucked it up somewhat.

--roboticus

Re: execution log
created: 2006-05-08 04:31:00

If you want an internal solution, you could try something like writing a short sub or module which redirects STDOUT and STDERR into files, e.g

use FindBin        ();
use File::Basename ();

sub RedirectOutputToFiles {
  my $scriptName = File::Basename::basename($0);
  my $stdoutFile = "$FindBin::Bin/$scriptName.stdout";
  my $stderrFile = "$FindBin::Bin/$scriptName.stderr";

  open (STDOUT, ">", $stdoutFile)
    or die "Error: couldn't redirect STDOUT: '$stdoutFile': $!";

  open (STDERR, ">", $stderrFile)
    or die "Error: couldn't redirect STDERR: '$stderrFile': $!";

} # RedirectOutputToFiles

or the like, and then just execute the sub somehow

Best regards,
perl -e "s>>*F>e=>y)\*martinF)stronat)=>print,print v8.8.8.32.11.32"

Re: execution log
created: 2006-05-08 09:34:43

If you mean logging from within a perl script, I wrote the package below for operations logging. It could (should?) be objectified (so you can have more than one logstream per application instance). If need be, you could also integrate it with an external logging service, e.g., syslog (*nix) or the Windows Event Service. However, there are undoubtedly extant perl modules which offer this.

Again, this code is intended for logging operations and is probably not appropriate for debug tracing. For the latter purpose, I've written a separate package with more suitable usage and formatting conventions (indents (someday!), trace levels (ditto), no timestamps, etc.). As well, there must be other debug tracing packages out there.

Regards,
Michael


use Time::Local;

# ============================================== #
# global state-of-the-module variables           #
# ============================================== #
my $_logstarted=0;
my $LOG; undef $LOG;
my @_logstack=();

# ============================================== #
# log 'stack' management                         #
# ---------------------------------------------- #
# Enables inclusion in logged messages of the    #
# name of the subroutine logging a particular    #
# message for diagnostics and debugging.         #
# ---------------------------------------------- #
# usage:                                         #
#     logstack('push', )                 #
#     logstack('pop')                            #
#     logstack('clear')                          #
#     logstack()                                 #
# ---------------------------------------------- #
# logstack('push', $caller), logstack('pop')     #
# and logstack() return the callstack as a       #
# string of colon-separated fields;              #
# logstack('clear') returns numeric 1.           #
# ---------------------------------------------- #
# To work correctly, requires subroutines        #
# to call logstack('push', $callername) on       #
# entry and logstack('pop') on return            #
# ---------------------------------------------- #
# EXPORTED                                       #
# ============================================== #
# examples:
# 16 Apr 2006 16:05:50 myfiles: process: catalog: found 35 file(s)
# 02 Feb 2006 10:48:02 myfiles: process: archive: error moving todaysfiles.html: No such file or directory

sub logstack {
    return if !$_logstarted;
    my $op=@_ ? shift : "";
    @_logstack=(), return 1 if ($op eq 'clear');
    push @_logstack, @_     if $op eq 'push';
    pop  @_logstack         if $op eq 'pop';
    return join (': ', @_logstack);
}

# ============================================== #
# logstart -- initializes log service            #
# ---------------------------------------------- #
# usage:                                         #
#     logstart(                                  #
#         directory => $logdirectory,            #
#         filename  => $logfilename,             #
#         caller    => $callername,              #
#         path      => $logpath,                 #
#         error     => \$errmsg)                 #
#                                                #
# The logfile must be specified with either      #
#  or [, ],        #
# with  used if both are passed.        #
#                                                #
# The logfile is the only required parameter.    #
# ---------------------------------------------- #
# Returns numeric 1 or 0, respectively,          #
# on success or failure                          #
#                                                #
# On error or failure, logstart() returns        #
# an error message via the optional error        #
# parameter.                                     #
# ---------------------------------------------- #
# EXPORTED                                       #
# ============================================== #

sub logstart {
    return if $_logstarted || (@_<2);
    my $logdir="";
    my $logfile="";
    my $msg=""; undef $msg;
    my $caller="";
    my $logpath="";
    my $error; undef $error;
    my %argh=();

    # collect and validate function args
    while (@_) {
        my $key=shift;
        my $value=shift;
        $argh{$key}=$value;
    }

    $caller=$argh{caller} if exists($argh{caller});
    $msg=$argh{message} if exists($argh{message});
    $error=$argh{error} if exists($argh{error});

    if (exists $argh{path}) {
        $logpath=$argh{path};
    }
    elsif ((exists $argh{directory}) && (exists $argh{filename})) {
        $argh{directory}=~s/\\$//;
        $logdir=$argh{directory};
        $logfile=$argh{filename};
        $logpath=$logdir."\\".$logfile;
    }

    else {
        $$error="missing logfile directory and filename" if $error;
        return 0;
    }

    # create log subdirectory if necessary
    if (!(-e $logdir) && !(mkdir $logdir)) {
        $$error="couldn't create log directory ".$logdir.": ".$!
            if $error;
        return 0;
    }

    # open logfile
    if (!(open($LOG, "+>>:utf8", $logpath))) {
        $$error="error opening logfile ".$logpath.": ".$! if $error;
        return 0;
    }
    $LOG->autoflush(1);
    print $LOG "\n";
    $_logstarted=1;

    logstack('clear');
    logstack('push', $caller) if $caller;
    logstack('push', 'logstart');
    logmsg($msg) if $msg;
    logstack('pop');
    logstack('pop') if $caller;

    return 1;
}

# ============================================== #
# logstop -- shuts down log service              #
# ---------------------------------------------- #
# usage:                                         #
#     logstop()                                  #
#     logstop($lastwords)                        #
#                                                #
# The optional parameter $lastwords is a         #
# message to log before closing the logfile      #
# ---------------------------------------------- #
# EXPORTED                                       #
# ============================================== #

sub logstop {
    return if !$_logstarted;
    my $msg=shift;
    $msg and logmsg($msg);
    close $LOG;
    undef $LOG;
    $_logstarted=0;
    logstack('clear');
    return;
}

# ============================================== #
# logstr -- composes formatted string of form    #
#  where  #
# date & time is of form                         #
# 
:: # # ---------------------------------------------- # # usage: # # logstr() # # logstr($msg) # # ---------------------------------------------- # # logstr() with no parameters returns # # a formatted timestamp only # # ---------------------------------------------- # # EXPORTED # # ============================================== # sub logstr { my $msg=shift; $msg=$msg?$msg:""; my ($sec, $min, $hour, $day, $month, $year, $weekday, $yday, $dst)=localtime(time); $year+=1900; my $timestamp=sprintf("%02d", $day)." ".$mmm[$month]." ". $year." ".sprintf("%02d", $hour).":".sprintf("%02d", $min). ":".sprintf("%02d", $sec); $msg=$timestamp."\t".join (': ', @_logstack).": ".$msg; return $msg } # ============================================== # # logmsg -- writes formatted string of form # # # # to the logfile specified when the log # # service was started with logstart() # # # # The content of is # # managed using logstack() # # ---------------------------------------------- # # usage: # # logmsg($msg) # # ---------------------------------------------- # # Does nothing if $msg is missing or the log # # service wasn't previously started with # # logstart() # # ---------------------------------------------- # # EXPORTED # # ============================================== # sub logmsg { return if !$_logstarted || !(defined $LOG) || !@_; my $msg=logstr(shift()); print $LOG $msg."\n"; # print $msg."\n"; # optionally print duplicate message to STDOUT return $msg; }

keywords: log;logging;event;events;syslog;event logging;execution log;execution logging;event log; audit trail;log service;logging service;event service;

Re^2: execution log
created: 2006-05-08 17:09:28
Thank you, mscudder! BTW...the expected use is simply for logging the execution of a working script, not for debugging, anyway. I had nearly given up on finding an event log, and will gladly use your package. Now...excuse the Perl-newbie dumb question - since this is a package, how do I use it in a script? Do I code a "use" statement, or perform an "exec" or "system"?
Re^3: execution log
created: 2006-05-09 14:24:39
The simplest option -- if you don't care about reusability or maintainability -- is simply to paste the code into the file containing your script.

To create a (reusable) module, create a file in the format below, i.e. starting with the section labeled module interface, followed by the actual module code, and concluding with the numeral 1 (which should be the very last character in the file). Name the module file using the extension .pm, e.g., logmsg.pm.

Locate the .pm file in one of the module directories searched by the perl interpreter:

  1. Same directory as the script.
  2. One of the standard perl extension directories for your platform and perl distribution.
  3. Your own perl extension directory, in which case you'll have to add the library to the interpreter's search path using one of the perl -I command line option, @INC array, PERL5LIB environmental variable, lib pragma, or FindBin module.

To import the module into (make it accessible from within) your script, include the statement use Logmsg. The module name must be exactly as it appears in the corresponding package statement in the .pm file, including capitalization. By convention, at least the first letter of the module name should be upper case.

Good luck!

Best regards,
Michael

# ============================================== #
# module interface                               #
# ============================================== #
package Logmsg;  # for example -- name as you think best
use strict;
use Exporter();
our ($VERSION, @ISA, @EXPORT, @EXPORT_OK, %EXPORT_TAGS);

# set the version for version checking
$VERSION = 1.0;
@ISA     = qw(Exporter);
@EXPORT  = qw(           # autoexported symbols
    &logstart
    &logmsg
    &logstr
    &logstop
    &logstack
);
%EXPORT_TAGS = ();       # symbol groupings
@EXPORT_OK   = ();       # symbols exported on request

# ============================================== # 
# module code                                    #
# ============================================== #


# ============================================== # 
# at end of file                                 #
# ============================================== #
1;

References

Programming with Perl Modules: Chapter 1, Sebastopol, CA:O'Reilly Media, Inc.

Perlmod - Perl Modules

Perlmodlib - Constructing New Perl Modules and Finding Existing Ones

Chapter 10, "Packages" in Wall, Larry, Tom Christiansen, and Jon Orwant, Programming Perl, Third Edition, Sebastopol, CA:O'Reilly Media, Inc., 2000, ISBN 0596000278.

Chapter 11, "Modules" in Programming Perl.

Chapter 12, "Packages, Libraries, and Modules," in Christiansen, Tom and Nathan Torkington, Perl Cookbook, Second Edition, Sebastopol, CA:O'Reilly Media, Inc., 2003, ISBN 0596003137.

Re^4: execution log
created: 2006-05-09 16:31:40
Wow - thank you SO much, mscudder! I'm working on a project to convert our DOS .bat scripts to Perl, while learning both script languages, and I spend a lot of time in the state of confusion. I appreciate your clear writing style, while still managing to avoid talking down to me.
Re^5: execution log
created: 2006-05-11 23:06:38

I hope it was of help.

Thank you for your most kind complement.

Best,
Michael

Re: execution log
created: 2006-05-09 16:49:05
How do you log the execution of a Perl script?

Allow me to mention a more compex, but complete, option. Perl has a number of logging modules on CPAN; my personal choice in my projects is Log::Log4perl. It's a bit complex -- approx. 10-15 lines of additonal code for the "base model". And installing the module via Windows take a bit of work, as well. Yet there's nothing better than proper logging, esp. one that can log to screen, files, emails, and even Windows Event Logs.

Seems like overkill for a script? Not really. If you're producing tons of debugging code, having it segmented in the ways programs like Log::Log4perl allow gives you the ability to track just one section of the code you're running. The Log4perl FAQ page also gives a code sample for logging unexpected failures, a powerful tool for those who run cron jobs.

Getting STDOUT and STDERR is good, getting solid logging rocks. :) A good tutorial is on perl.com

----Asim, known to some as Woodrow.

Re^2: execution log
created: 2006-05-11 23:23:20

Thank you for your recommendation of Log::Log4perl. Excellent!

Regards,
Michael

perlmonks.org content © perlmonks.org and Asim, ikegami, johngg, mscudder, roboticus, strat, yburge

prlmnks.org © 2006 edmund von der burg (eccles & toad)

v 0.03