Log4perl script logs OK only initially

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

Update: See my reply below to jasonk. I've recoded it to include chunks from the Schedule::Cron and log4perl manpages, but now it returns nothing.

I've written a script to ping servers using a Schedule::Cron job and log using Log4perl. It logs the first time the cron job runs, but thereafter, it simply logs a blank message:

2007/12/28 22:16:00 test.pl 84> INFO: this is a test
2007/12/28 22:16:00 test.pl 84> 0:
2007/12/28 22:17:00 test.pl 84> 0:
2007/12/28 22:17:00 test.pl 84> INFO: this is a test
2007/12/28 22:17:00 test.pl 84> 0:
2007/12/28 22:18:00 test.pl 84> 0:
2007/12/28 22:18:00 test.pl 84> INFO: this is a test
2007/12/28 22:18:00 test.pl 84> 0:
[download]

I know the cron job is writing correctly, as the testfile shows the correct times:

# tail /tmp/testfile
Fri Dec 28 22:12:00 GMT 2007
...
Fri Dec 28 22:18:00 GMT 2007
Fri Dec 28 22:19:00 GMT 2007
Fri Dec 28 22:20:00 GMT 2007
Fri Dec 28 22:21:00 GMT 2007
[download]

I doublechecked and found no other test.pl processes running.

My guess is that it's finding null for level, converting to int, and printing it... but I don't understand why.

As I'm not sure if Schedule::Cron is passing the data correctly or whether something is amiss with Log4perl , I've included the code below.

Thoughts, anyone?

/more

#!/usr/bin/perl 

use Data::Dumper;
use Carp;
use Schedule::Cron;
use Sys::Hostname;
use Log::Log4perl qw(get_logger);

###############################################
#Variable declarations
my $rootdir = "/usr/local/appname";
my $script = "test";


###############################################
#MAIN
#OpenLog ($logfile);

my $cron = new Schedule::Cron(\&dispatcher, 
                nofork => 1,    
                log => \&Log,
                );
$cron->add_entry("* * * * *", 
         {'subroutine' => \&TestSub,
          }
        );

$cron->run(detach=>1, pid_file=>"$rootdir/bin/$script.pid");


######################################################
sub dispatcher { 
   print "ID:   ",shift,"\n"; 
   print "Args: ","@_","\n";
}


######################################################
sub TestSub {
    Log ("INFO", "", "this is a test");
    `date >> /tmp/testfile`;
}

######################################################
sub Log {
        my ($level, $subject, $msg) = @_;

    my $conf = q(
        log4perl.category.appname    = INFO, Logfile
            log4perl.appender.Logfile          = Log::Log4perl::Append
+er::File
            log4perl.appender.Logfile.filename = /usr/local/appname/lo
+gs/appname.pl.log 
            log4perl.appender.Logfile.layout = \
            Log::Log4perl::Layout::PatternLayout
            log4perl.appender.Logfile.layout.ConversionPattern = %d %F
+{1} %L> %m %n
        );
    
        Log::Log4perl::init(\$conf);
    
        my $logger = get_logger("appname");
    $logger->info("$level: $msg");
        if ($level eq "ERR") {
        $logger->error($msg);
        }

}
[download]

-- Burvil

Comment on Log4perl script logs OK only initially Select or Download Code

Replies are listed 'Best First'.

Re: Log4perl script logs OK only initially
by jasonk (Parson) on Dec 29, 2007 at 01:01 UTC

Your log method expects three arguments, but you are passing it as a log argument to Schedule::Cron, which is only going to call it with two arguments, and the first one will be either 0, 1, or 2 depending on the level of the message, so when you call Log directly in your TestSub, it works as expected, but when Schedule::Cron calls it, you are only logging the first argument, which is 0, and ignoring the second one (which you assigned to $subject, but then didn't do anything with). The Schedule::Cron documentation includes an example of how to use Log::Log4perl as a logger.

We're not surrounded, we're in a target-rich environment!

[reply]

Re^2: Log4perl script logs OK only initially

by bowei_99 (Friar) on Dec 30, 2007 at 05:54 UTC


my $log_method = sub {
      my ($level,$msg) = @_;
      my $DBG_MAP = { 0 => $INFO, 1 => $WARN, 2 => $ERROR };
        my $conf = q(
                log4perl.category.appname  = INFO, Logfile
                log4perl.appender.Logfile          = Log::Log4perl::Ap
+pender::File
                log4perl.appender.Logfile.filename = /usr/local/eFTP/l
+ogs/appname.pl.log
                log4perl.appender.Logfile.layout = \
                Log::Log4perl::Layout::PatternLayout
                log4perl.appender.Logfile.layout.ConversionPattern = %
+d %F{1} %L> %m %n
        );

        Log::Log4perl::init(\$conf);

      my $logger = Log::Log4Perl->get_logger("appname");
      $logger->log($DBG_MAP->{$level},$msg);
};
[download]

my $cron = new Schedule::Cron(\&dispatcher,
                                nofork => 1,
                                #log => \&Log,
                                log => $log_method,
                                );
$cron->add_entry("* * * * *",
                 {'subroutine' => \&TestSub(),
                  'arguments' => [ "INFO", "a test" ],
                  }
                );
[download]

Again, now there's nothing logged to the file at all. The file /tmp/testfile is updated, so I know TestSub ran, but nothing updated in appname.pl.log, and no Schedule::Cron process in the process table after a couple minutes.

Is there something I'm not setting the Schedule::Cron object? What else could be causing not to log at all, much less quit?

-- Burvil

[reply]
[d/l]
[select]

Re^3: Log4perl script logs OK only initially

by bowei_99 (Friar) on Jan 02, 2008 at 18:10 UTC

$cron->add_entry("0 5 * * *",
                 {'subroutine' => \&TestSub,
                  'arguments' => [ ],
                  }
                );
[download]

-- Burvil

[reply]
[d/l]