[log4perl-devel] Intermittent problems when using signal to reread log configuration

[Robert J. <yad...@sn...>]

I have been using Log4perl for quite some time in a large project of mine.   There are about 20 perl programs, all of which should always be running.  I'm using init_and_watch to allow users to update the configuration file; i.e:

    # Init Log4perl
    Log::Log4perl->init_and_watch("../ANSlog.conf",'HUP');
    $logger = get_logger("category")

After updating the config file, I use a script to send SIGHUP to all the currently running processes (simple "kill -HUP <PID>").

Most of the time (I'd guess ~80%), this works fine.  When it doesn't work, I get the following error on STDERR (even though I've wrapped STDERR with a "Trapper" as described in the FAQ):

	Can't call method "log" on an undefined value at /opt/ActivePerl-5.8/lib/site_perl/5.8.7/Log/Log4perl/Appender.pm line 189.

And the perl program dies.

I'm using ActivePerl 5.8.7 due to an restriction from a third-party Perl module; I can't update perl itself or use another perl distribution.

I'm using Log4perl 1.20.  The system is CentOS 4.2.

My log4perl configuration is rather large, but it is below.  I tried removing the Database appender from the configuration (i.e. leaving only the File appender "Logfile"), but it still happens without it.


#-----------------------------------------------------------------------
##
## Root logger threshold and appenders
##
log4perl.rootLogger = DEBUG

##
## Categories for each ANS module
##
log4perl.category.ANS           = INFO, Logfile
log4perl.category.ANS.asistlog  = INFO, Database
log4perl.category.ANS.email     = INFO, Database
log4perl.category.ANS.event     = INFO, Database
log4perl.category.ANS.event.main = INFO
log4perl.category.ANS.event.readconfig = INFO
log4perl.category.ANS.event.forkchildren = INFO
log4perl.category.ANS.event.refork = INFO
log4perl.category.ANS.event.housekeeping = INFO
log4perl.category.ANS.event.connopen = INFO
log4perl.category.ANS.event.connclose = INFO
log4perl.category.ANS.event.connquery = WARN
log4perl.category.ANS.event.repeat = INFO
log4perl.category.ANS.event.GetFieldValue = INFO
log4perl.category.ANS.heartbeat = INFO, Database
log4perl.category.ANS.htmlizer  = INFO, Database
# This category is special -- no inheritance from ANS category,
# so messages only go to the alert database
log4perl.category.htmlizer.sql  = INFO, AlertDatabase
log4perl.category.asistlog.sql  = INFO, ASISTDatabase, DMZDatabase
#
log4perl.category.ANS.component = INFO, Database
log4perl.category.ANS.satwatch                  = INFO, Database
log4perl.category.ANS.satwatch.parse            = INFO
# ****** NOTE!  DEBUG output for Catalog iS HUUUUUGE ********
log4perl.category.ANS.satwatch.catalog          = INFO
log4perl.category.ANS.satwatch.filter           = INFO
log4perl.category.ANS.satwatch.typehandler      = INFO
log4perl.category.ANS.satwatch.grouphandler     = INFO
log4perl.category.ANS.satwatch.registerhandler  = INFO
log4perl.category.ANS.satwatch.filterhandler    = INFO
log4perl.category.ANS.satwatch.eventhandler     = INFO
log4perl.category.ANS.satwatch.regexphandler    = INFO
log4perl.category.ANS.satwatch.occurshandler    = INFO
log4perl.category.ANS.satwatch.intervalhandler  = INFO
log4perl.category.ANS.satwatch.ignore           = INFO
log4perl.category.ANS.satwatch.watch            = INFO
log4perl.category.ANS.satwatch.clear            = INFO
log4perl.category.ANS.satwatch.flush            = INFO
log4perl.category.ANS.satwatch.flushnow         = INFO
log4perl.category.ANS.satwatch.cleaner          = INFO
log4perl.category.ANS.satwatch.cleanup          = INFO
log4perl.category.ANS.source    = INFO, Database
log4perl.category.ANS.target    = INFO, SyncDatabase
log4perl.category.ANS.trapper   = INFO, Database

##
## Logfile appender
##
log4perl.appender.Logfile       = Log::Log4perl::Appender::File
log4perl.appender.Logfile.filename = \
        sub { if ($ENV{'ANSROOT'}) { \
                return "$ENV{'ANSROOT'}/ANSlog.txt" \
        } else { \
                die "ENV{ANSROOT} not defined!" \
        } }
log4perl.appender.Logfile.mode  = append
log4perl.appender.Logfile.recreate = 1
log4perl.appender.Logfile.recreate_check_signal = USR1
#log4perl.appender.Logfile.recreate_check_interval = 5
log4perl.appender.Logfile.layout= Log::Log4perl::Layout::PatternLayout
log4perl.appender.Logfile.layout.ConversionPattern = \
         %d{yyyy-DDD/HH:mm:ss} %-5p %F{2} %P %m%n

##
## Screen Appender
##
log4perl.appender.Screen         = Log::Log4perl::Appender::Screen
log4perl.appender.Screen.stderr  = 0
log4perl.appender.Screen.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.Screen.layout.ConversionPattern = \
        %d{yyyy-DDD/HH:mm:ss} %-5p %F{2} %P %m%n

##
## Database Appender
##
# NOTE: DBI_Buffer uses all options from Log::Log4perl::Appender::DBI
log4perl.appender.Database              = Log::Log4perl::Appender::DBI
log4perl.appender.Database.usePreparedStmt = 1
log4perl.appender.Database.layout       = Log::Log4perl::Layout::NoopLayout
log4perl.appender.Database.datasource   = DBI:mysql:database=ansdb:host=localhost;mysql_auto_reconnect=1
log4perl.appender.Database.username     = foo
log4perl.appender.Database.password     = bar
log4perl.appender.Database.logbuffer    = 4000
log4perl.appender.Database.errorappender= Logfile
log4perl.appender.Database.errorstodatabase= 1
log4perl.appender.Database.sql          = \
        insert into anslog              \
        (date, loglevel, filename, hostname, PID, message) \
        values (?,?,?,?,?,?)
log4perl.appender.Database.params.1   = %d{yyyy-DDD/HH:mm:ss}
log4perl.appender.Database.params.2   = %p
log4perl.appender.Database.params.3   = %F{2}
log4perl.appender.Database.params.4   = %H
log4perl.appender.Database.params.5   = %P
log4perl.appender.Database.params.6   = %m

##
## Alert Database Appender
##
# NOTE: DBI_Buffer uses all options from Log::Log4perl::Appender::DBI
log4perl.appender.AlertDatabase                 = DBI_Buffer
log4perl.appender.AlertDatabase.layout          = Log::Log4perl::Layout::NoopLayout
log4perl.appender.AlertDatabase.warp_message    = 0
log4perl.appender.AlertDatabase.datasource      = DBI:mysql:database=ansdb:host=localhost;mysql_auto_reconnect=1
log4perl.appender.AlertDatabase.username        = foo
log4perl.appender.AlertDatabase.password        = bar
log4perl.appender.AlertDatabase.logbuffer       = 4000
log4perl.appender.AlertDatabase.errorappender   = Logfile
log4perl.appender.AlertDatabase.errorstodatabase= 0
log4perl.appender.AlertDatabase.sql     = \
        insert into alerts              \
        (date, loglevel, filename, hostname, PID, \
                timestamp, emailgroup, message) \
        values (?,?,?,?,?,?,?,?)
log4perl.appender.AlertDatabase.params.1   = %d{yyyy-DDD/HH:mm:ss}
log4perl.appender.AlertDatabase.params.2   = %p
log4perl.appender.AlertDatabase.params.3   = %F{2}
log4perl.appender.AlertDatabase.params.4   = %H
log4perl.appender.AlertDatabase.params.5   = %P
                                      #6 is timestamp from log call
                                      #7 is emailgroup from log call
                                      #8 is message from log call

##
## Define a filter routine to remove SDO Commands
## from the event log
##
log4perl.filter.CommandFilter   = sub { \
        !/CMH-I:CMD/ \
        };

##
## ASIST Database Appender
##
# NOTE: DBI_Buffer uses all options from Log::Log4perl::Appender::DBI
log4perl.appender.ASISTDatabase                 = DBI_Buffer
log4perl.appender.ASISTDatabase.Filter          = CommandFilter
log4perl.appender.ASISTDatabase.layout          = Log::Log4perl::Layout::NoopLayout
log4perl.appender.ASISTDatabase.warp_message    = 0
log4perl.appender.ASISTDatabase.datasource      = DBI:mysql:database=asistdb:host=localhost;mysql_auto_reconnect=1
log4perl.appender.ASISTDatabase.username        = foo
log4perl.appender.ASISTDatabase.password        = bar
log4perl.appender.ASISTDatabase.logbuffer       = 4000
log4perl.appender.ASISTDatabase.errorappender   = Logfile
log4perl.appender.ASISTDatabase.errorstodatabase = 0
log4perl.appender.ASISTDatabase.sql     = \
        insert into events              \
        (date, loglevel, filename, hostname, PID, \
                asisthost, timestamp, class, message) \
        values (?,?,?,?,?,?,?,?,?)
log4perl.appender.ASISTDatabase.params.1   = %d{yyyy-DDD/HH:mm:ss}
log4perl.appender.ASISTDatabase.params.2   = %p
log4perl.appender.ASISTDatabase.params.3   = %F{2}
log4perl.appender.ASISTDatabase.params.4   = %H
log4perl.appender.ASISTDatabase.params.5   = %P
                                      #6 is asisthost from log call
                                      #7 is timestamp from log call
                                      #8 is class from log call
                                      #9 is message from log call
##
##
## DMZ Database Appender
##
# NOTE: DBI_Buffer uses all options from Log::Log4perl::Appender::DBI
log4perl.appender.DMZDatabase                   = DBI_Buffer
log4perl.appender.DMZDatabase.Filter            = CommandFilter
log4perl.appender.DMZDatabase.layout            = Log::Log4perl::Layout::NoopLayout
log4perl.appender.DMZDatabase.warp_message      = 0
log4perl.appender.DMZDatabase.datasource        = DBI:mysql:database=asistdb:host=remotesys;mysql_auto_reconnect=1
log4perl.appender.DMZDatabase.username          = foo
log4perl.appender.DMZDatabase.password          = bar
log4perl.appender.DMZDatabase.logbuffer         = 4000
log4perl.appender.DMZDatabase.errorappender     = Logfile
log4perl.appender.DMZDatabase.errorstodatabase  = 0
log4perl.appender.DMZDatabase.sql       = \
        insert into events              \
        (date, loglevel, filename, hostname, PID, \
                asisthost, timestamp, class, message) \
        values (?,?,?,?,?,?,?,?,?)
log4perl.appender.DMZDatabase.params.1   = %d{yyyy-DDD/HH:mm:ss}
log4perl.appender.DMZDatabase.params.2   = %p
log4perl.appender.DMZDatabase.params.3   = %F{2}
log4perl.appender.DMZDatabase.params.4   = %H
log4perl.appender.DMZDatabase.params.5   = %P
                                      #6 is asisthost from log call
                                      #7 is timestamp from log call
                                      #8 is class from log call
                                      #9 is message from log call

##
## DB Syncronizer
##
# Technically, only the forked children for event.pl and target.pl
# need to be Sync'd, but we are syncing all of the modules
# If performance becomes an issue, try syncing only event.pl and target.pl
log4perl.appender.SyncDatabase            = Log::Log4perl::Appender::Synchronized
log4perl.appender.SyncDatabase.appender   = Database
# Random semaphore key; otherwise they clobber each other
log4perl.appender.SyncDatabase.key        = sub { int(rand(10000)); }


-- 
Thanks,
Rob