Mike Schilli m-at-perlmeister.com |log4perl_sourceforge| wrote:
> On Tue, 24 Feb 2009, Robert Jacobson wrote:
> 
>> Those are mostly the expected values from the Layout I specified
>> (time, log level, script name, hostname, PID, ?????, message).
> 
> That's peculiar ... what does your layout look like?
> 
> It's hard to diagnose the problem without code that reproduces it, can
> you post a stripped-down version of your appender?


I attached the appender code (full version), a configuration file, and a
test program in the first post I made.   I could understand how you'd
want a stripped-down version of the appender :)

I wasn't sure what would happen if I stripped it down -- but it turns
out that even with only two subs defined (new and post_init), the
appender exhibits the problem of persistent DB connections.

The stripped-down version of DBI_Buffer is attached, along with the test
program and config.  (again, modify the database config to match your
database).

For the error "called 7 bind variables when 6 are needed...", I added a
little debug to DBI.pm (while still using my subclassed appender).  With
the "l4_depends_on" code in the stripped-down DBI_Buffer.pm i.e.:

    if ($self->{errorappender}) {
        # Pass back the appender to be synchronized as a dependency
        # to the configuration file parser
        push @{$p{l4p_depends_on}}, $self->{errorappender};
        push @{$p{l4p_post_config_subs}}, sub { $self->post_init() };
    }


Then $p in DBI::calculate_bind_values shows the message as an array, e.g.:

calculate_bind_values Dump p:
$VAR1 = {
          'log4p_level' => 'INFO',
          'log4p_category' => 'ANS.component',
          'level' => 1,
          'name' => 'Database',
          'message' => [
                         'Starting ....'
                       ]
        };

I thought the message array ref would get compressed to a scalar string
value, but that doesn't seem to be the case.

I tried messing with the warp_message values of the Logfile and Database
appenders, but I still end up with 7 bind values no matter what
warp_message setting I use.

-- 
Rob
package DBI_Buffer;
use base ("Log::Log4perl::Appender::DBI");

use strict;
use warnings;

use Time::HiRes;
use Data::Dumper;

use vars qw ($VERSION);
$VERSION = "1.06";

##########################################
sub new {
###########################################
        my($proto, %p) = @_;
        my $class = ref $proto || $proto;

        my $self = bless {}, $class;

        $self->_init(%p);

        my %defaults = (
                reconnect_attempts => 1,
                reconnect_sleep    => 0,
                logbuffer          => 2000,
                buffer             => [],
                connected          => 1,
                errorstodatabase   => 1,
                signal_caught      => 0,
        );

        for (keys %defaults) {
                if(exists $p{$_}) {
                        $self->{$_} = $p{$_};
                } else {
                        $self->{$_} = $defaults{$_};
                }
        }

        #e.g.
        #log4j.appender.DBAppndr.params.1 = %p  
        #log4j.appender.DBAppndr.params.2 = %5.5m
        foreach my $pnum (keys %{$p{params}}){
                $self->{bind_value_layouts}{$pnum} = 
                                Log::Log4perl::Layout::PatternLayout->new(
                                        {ConversionPattern => {value  => 
$p{params}->{$pnum}}});
        }
        #'bind_value_layouts' now contains a PatternLayout
        #for each parameter heading for the Sql engine

        $self->{SQL} = $p{sql}; #save for error msg later on

        $self->{MAX_COL_SIZE} = $p{max_col_size};

        $self->{BUFFERSIZE} = $p{bufferSize} || 1; 

        $self->{errorappender} = $p{errorappender} if exists $p{errorappender};

        $self->{errorstodatabase} = $p{errorstodatabase} if exists 
$p{errorstodatabase};

        $self->{flushsignal} = $p{flushsignal} if exists $p{flushsignal};

        if ($self->{flushsignal}) {
                #$self->{watcher} = Log::Log4perl::Config::Watch->new(
                        #file   => '/dev/null', # no file needed
                        #signal => $self->{flushsignal}
                #);
                # Install a signal handler
                $SIG{$self->{flushsignal}} = sub {
                        $self->{signal_caught} = 1;
                        print STDERR __PACKAGE__.": We get signal!\n";
                        $self->flush;
                        $self->{signal_caught} = 0;
                }
        }

        # Run our post_init method in the configurator after
        # all appenders have been defined to make sure the
        # appenders we're connecting to really exist.
        if ($self->{errorappender}) {
                push @{$p{l4p_post_config_subs}}, sub { $self->post_init() };
        }
        
        if ($p{usePreparedStmt}) {
                $self->{sth} = $self->create_statement($p{sql});
                $self->{usePreparedStmt} = 1;
        }else{
                $self->{layout} = Log::Log4perl::Layout::PatternLayout->new(
                                        {ConversionPattern => {value  => 
$p{sql}}});
        }

        if ($self->{usePreparedStmt} &&  $self->{bufferSize}){
                warn "Log4perl: you've defined both usePreparedStmt and 
bufferSize \n".
                "in your appender '$p{name}'--\n".
                "I'm going to ignore bufferSize and just use a prepared stmt\n";
        }

        return $self;
}


###########################################
sub post_init {
###########################################
        my($self) = @_;

        if(! exists $self->{errorappender}) {
           die "No error appender defined for " . __PACKAGE__;
        }

        my $appenders = Log::Log4perl->appenders();
        my $appender = Log::Log4perl->appenders()->{$self->{errorappender}};

        if(! defined $appender) {
           die "Appender $self->{errorappender} not defined (yet) when " .
                   __PACKAGE__ . " needed it";
        }

        $self->{app} = $appender;
}

sub DESTROY {
        my $self = shift;

        #my $app = $self->{errorappender};
        #my %params = 
        #{ name    => $app,
          #level   => 'DEBUG',
          #message => "DESTROYING DBI_Buffer",
          #log4p_category => "ANS.event",
          #log4p_level  => 0,
        #};
#
        #my $depth = 3;

        #if ($self->{errorappender}) {
                #$Log::Log4perl::caller_depth += $depth;
                #$self->{app}->log(\%params, $params{log4p_category}, 
$params{log4p_level});
                #$Log::Log4perl::caller_depth -= $depth;
        #}

        $self->{dying} = 1;
        $self->SUPER::DESTROY();

}

1;

__END__


=head1 NAME

DBI_Buffer - subclass of L<Log::Log4perl::Appender::DBI>, with buffering

=head1 SYNOPSIS

    my $config = <<'EOT';
    log4j.category = WARN, DBAppndr
    log4j.appender.DBAppndr               = DBI_Buffer
    log4j.appender.DBAppndr.datasource    = 
DBI:mysql:database=logdb:host=localhost
    log4j.appender.DBAppndr.username      = bobjones
    log4j.appender.DBAppndr.password      = 12345
    log4j.appender.DBAppndr.logbuffer     = 2000
    log4j.appender.DBAppndr.errorappender = Logfile
    log4j.appender.DBAppndr.flushsignal   = USR2
    log4j.appender.DBAppndr.errorstodatabase   = 1
    log4j.appender.DBAppndr.sql         = \
       insert into log4perltest           \
       (date, loglevel, filename, hostname, PID, message) \
       values (?,?,?,?,?,?)
    log4j.appender.DBAppndr.params.1 = %d{yyyy/DDD/HH:mm:ss}
    log4j.appender.DBAppndr.params.2 = %p    
    log4j.appender.DBAppndr.params.3 = %F{2}    
    log4j.appender.DBAppndr.params.4 = %H    
    log4j.appender.DBAppndr.params.5 = %P
    log4j.appender.DBAppndr.params.6 = %m
        
    
    log4j.appender.DBAppndr.usePreparedStmt = 1
    
    #just pass through the array of message items in the log statement 
    log4j.appender.DBAppndr.layout    = Log::Log4perl::Layout::NoopLayout
    log4j.appender.DBAppndr.warp_message = 0
    EOT
    
    $logger->warn( $custid, 'big problem!!', $ip_addr );


=head1 DESCRIPTION

This is a sepecialized subclass of Log::Log4perl::Appender::DBI, with
provision for an in-memory buffer of log messages for when the logger
cannot connect to the database for whatever reason; i.e. if the database
is down, messages are buffered until the database comes back up.

Buffer size is controlled via the logbuffer option.

=head1 OPTIONS

In addition to the options supported by L<Log::Log4perl::Appender::DBI>, 
DBI_Buffer supports the following options:

=over 4

=item logbuffer

The number of log messages to buffer in memory.  If the buffer is
exceeded, the oldest message is dropped.  The default size is 2000
messages.

=item errorappender

If errorappender is defined, and DBI_Buffer cannot connect to the database,
it will log error messages to this appender.  errorappender must be
defined in the Log4perl configuration, or DBI_Buffer will fail to init.

=item flushsignal

Normally, DBI_Buffer will only write messages to the database upon
receiving a log() request.  However, if the database goes down, and
messages are buffered, then DBI_Buffer will not notice the database
is available until the next log() call.  In other words, if log()
calls are infrequent, messages may remain in the buffer if the database
becomes available.  Send the flushsignal to the process in order to 
force DBI_Buffer to reconnect to the database and flush its buffer.

If DBI_Buffer cannot reconnect and flush, it will log an error to the
errorappender (if it is defined), or STDERR.

=item errorstodatabase

By default, DBI_Buffer will log connection errors to the database. To
turn off this behavior, set errorstodatabase to 0.

=back

=head1 NOTES

DBI_Buffer has not been tested when the log() call has more than one
element and warp_message=0 e.g.

        $logger->info( $arg1, $arg2, $arg3);

may not work. (If warp_message=1 -- the default -- then the arguments
will be joined into one element and so it will work fine)

=head1 AUTHOR

Robert Jacobson <..........................> January, 2007

=head1 SEE ALSO

L<Log::Log4perl::Appender::DBI>

=cut
##
## Categories for each ANS module
## 
log4perl.category.ANS           = DEBUG, Logfile, Database

##
## Logfile appender 
##
log4perl.appender.Logfile       = Log::Log4perl::Appender::File
log4perl.appender.Logfile.filename = 'ANSlog.txt'
log4perl.appender.Logfile.recreate = 1
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

##
## Database Appender
##
# NOTE: DBI_Buffer uses all options from Log::Log4perl::Appender::DBI
log4perl.appender.Database      = DBI_Buffer
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.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

#!/opt/ActivePerl-5.8/bin/perl

use Log::Log4perl qw(get_logger :levels);
use strict;

use lib ".";
Log::Log4perl->init_and_watch("log4perl.conf",'HUP');
my $logger = get_logger("ANS");

while (1) {
        $logger->info("info before sleep");
        $logger->debug("debug before sleep");
        sleep 5;
        $logger->info("info after sleep");
        $logger->debug("debug after sleep");
}

------------------------------------------------------------------------------
Open Source Business Conference (OSBC), March 24-25, 2009, San Francisco, CA
-OSBC tackles the biggest issue in open source: Open Sourcing the Enterprise
-Strategies to boost innovation and cut costs with open source participation
-Receive a $600 discount off the registration fee with the source code: SFAD
http://p.sf.net/sfu/XcvMzF8H
_______________________________________________
log4perl-devel mailing list
log4perl-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/log4perl-devel

Reply via email to