Re: [log4perl-devel] suggested patch for Log::Log4perl::Appender::DBI

[Mark B. <ma...@ex...>]

On 13 Dec 2007, at 17:52, Kevin M. Goess wrote:

> Mark Blackman wrote:
>> In the Appender::DBI man page, we see the following sentence,
>> "If there are more '?' placeholders than there are values in
>> your message, it will use undef for the rest." However, I was
>> unable to observe this behaviour with my configuration.
>
> Odd, it looks like it's working to me. What was the behavior you *did*
> obverve?  Can you send a test case to demonstrate the problem?

Well, I think the existing implementation isn't sufficiently general
to handle my requirement. I didn't examine the existing code
in excruciating detail, but  I believe the code path you mention is
only executed if you have at least one bind param defined in your
config. i.e

if ($self->{bind_value_layouts}) {

Secondly, as far as I could tell the implementation below
also seems to assume that the largest numbered bind param
will correspond to the last placeholder.

i.e. I couldn't spot in the code where the number of
placeholders expected in the prepared statemente was counted
or evaluated, only the largest numbered bind param.

On reflection, I could probably have achieved my requirement
to call the logger with between 1 and 4 arguments, but using
an artificially inserted bind param in the config file for
a fifth placeholder and the code path below would have taken
care of the undefs for me.

I've attached the details of my config, call and DBI_TRACE
output below if you're that keen to look at it.



>
> Here's the part of the existing code that handles the case, it  
> looks ok
> to me:
>
>                #here handle cases where we ran out of message bits
>                #before we ran out of bind_value_layouts, just keep  
> going
>             }elsif (ref $p->{message} eq 'ARRAY'){
>                 $msg = undef;
>                 $p->{message} = undef;
>
> I just added test cases to the unit test to demonstrate the  
> behavior and
> it looks ok.  Could you download this guy and see if it runs for you?
> (You'll need to 'mkdir -p t/tmp/')
>
> http://log4perl.cvs.sourceforge.net/*checkout*/log4perl/Log- 
> Log4perl/t/034DBI.t?revision=1.15&content-type=text%2Fplain
>

Your test runs fine for me, although I suspect it's because
the DBD::CSV driver doesn't mind getting too few arguments
for a prepared statement ->execute and the DBD::Pg driver does object
to too few arguments. That's pure speculation at this point
though. I made a brief attempt to convert the test to use DBD::Pg
but hit too many issues to carry on.

Perhaps I've missed some important point, and if so please educate me.

- Mark


log4perl config:
=========================================

log4perl.category.events = DEBUG, fx-dbi
log4perl.addivity.events = 0
log4perl.appender.fx-dbi=Log::Log4perl::Appender::DBI
log4perl.appender.fx-dbi.datasource  = dbi:Pg:dbname=fx;host=127.0.0.1
log4perl.appender.fx-dbi.username    = postgres81
log4perl.appender.fx-dbi.sql = \
        INSERT INTO event_log \
           (event, user_id,payment_id,order_id) \
           VALUES (?,?,?,?)
log4perl.appender.fx-dbi.layout    = Log::Log4perl::Layout::NoopLayout
log4perl.appender.fx-dbi.warp_message = 0
log4perl.appender.fx-dbi.usePreparedStmt = 1

my log4perl caller (snippet):
=============================================
use Log::Log4perl qw(get_logger);
my $events=get_logger('events');
$events->info('hello chuck');

DBI_TRACE=1 output:
=============================================
    <- prepare('INSERT INTO event_log (event,  
user_id,payment_id,order_id) VALUES (?,?,?,?)')= DBI::st=HASH 
(0x1a93bac) at DBI.pm line 88
     !! ERROR: -1 'called with 1 bind variables when 4 are  
needed' (err#0)
     <- execute('hello chuck')= undef at DBI.pm line 137
        ERROR: -1 'called with 1 bind variables when 4 are  
needed' (err#0)
     <- ping= 1 at DBI.pm line 147
     <- prepare('INSERT INTO event_log (event,  
user_id,payment_id,order_id) VALUES (?,?,?,?)')= DBI::st=HASH 
(0x1a93da4) at DBI.pm line 88
     <- DESTROY(DBI::st=HASH(1a93b94))= undef at DBI.pm line 168
     !! ERROR: -1 'called with 1 bind variables when 4 are  
needed' (err#0)
     <- execute('hello chuck')= undef at DBI.pm line 137
Log4perl: DBI appender failed to reconnect to database after 1  
attempt at /Volumes/cs/MBlackman/ffx/fx-live/FX/script/../lib/FX.pm  
line 85
Compilation failed in require at FX/script/fx_server.pl line 52.