###########################################
# Test using Log::Dispatch::DBI
# Kevin Goess <cpan@goess.org>
###########################################
our $table_name = "log4perltest$$";
BEGIN {
if($ENV{INTERNAL_DEBUG}) {
require Log::Log4perl::InternalDebug;
Log::Log4perl::InternalDebug->enable();
}
}
BEGIN {
use FindBin qw($Bin);
use lib "$Bin/lib";
require Log4perlInternalTest;
}
use Test::More;
use Log::Log4perl;
use warnings;
use strict;
BEGIN {
my $minversion = \%Log4perlInternalTest::MINVERSION;
eval {
require DBI;
die if $DBI::VERSION < $minversion->{ "DBI" };
require DBD::CSV;
die if $DBD::CSV::VERSION < $minversion->{ "DBD::CSV" };
require SQL::Statement;
die if $SQL::Statement::VERSION < $minversion->{ "SQL::Statement" };
};
if ($@) {
plan skip_all =>
"DBI $minversion->{ DBI } or " .
"DBD::CSV $minversion->{'DBD::CSV'} or " .
"SQL::Statement $minversion->{'SQL::Statement'} " .
"not installed, skipping tests\n";
}else{
plan tests => 33;
}
}
END {
unlink "t/tmp/$table_name";
rmdir "t/tmp";
}
mkdir "t/tmp" unless -d "t/tmp";
require DBI;
my $dbh = DBI->connect('DBI:CSV:f_dir=t/tmp','testuser','testpw',{ RaiseError => 1, PrintError => 1 });
$dbh->do("DROP TABLE $table_name") if -e "t/tmp/$table_name";
my $stmt = <<EOL;
CREATE TABLE $table_name (
loglevel char(9) ,
message char(128),
shortcaller char(5),
thingid char(6),
category char(16),
pkg char(16),
runtime1 char(16),
runtime2 char(16)
)
EOL
$dbh->do($stmt);
#creating a log statement where bind values 1,3,5 and 6 are
#calculated from conversion specifiers and 2,4,7,8 are
#calculated at runtime and fed to the $logger->whatever(...)
#statement
my $config = <<"EOT";
#log4j.category = WARN, DBAppndr, console
log4j.category = WARN, DBAppndr
log4j.appender.DBAppndr = Log::Log4perl::Appender::DBI
log4j.appender.DBAppndr.datasource = DBI:CSV:f_dir=t/tmp
log4j.appender.DBAppndr.username = bobjones
log4j.appender.DBAppndr.password = 12345
log4j.appender.DBAppndr.sql = \\
insert into $table_name \\
(loglevel, message, shortcaller, thingid, category, pkg, runtime1, runtime2) \\
values (?,?,?,?,?,?,?,?)
log4j.appender.DBAppndr.params.1 = %p
#---------------------------- #2 is message
log4j.appender.DBAppndr.params.3 = %5.5l
#---------------------------- #4 is thingid
log4j.appender.DBAppndr.params.5 = %c
log4j.appender.DBAppndr.params.6 = %C
#-----------------------------#7,8 are also runtime
log4j.appender.DBAppndr.bufferSize=2
log4j.appender.DBAppndr.warp_message=0
#noop layout to pass it through
log4j.appender.DBAppndr.layout = Log::Log4perl::Layout::NoopLayout
#a console appender for debugging
log4j.appender.console = Log::Log4perl::Appender::Screen
log4j.appender.console.layout = Log::Log4perl::Layout::SimpleLayout
EOT
Log::Log4perl::init(\$config);
# *********************
# check a category logger
my $logger = Log::Log4perl->get_logger("groceries.beer");
$logger->fatal('fatal message',1234,'foo',{aaa => 'aaa'});
#since we ARE buffering, that message shouldnt be there yet
{
local $/ = undef;
open (F, "t/tmp/$table_name");
my $got = <F>;
close F;
my $expected = <<EOL;
LOGLEVEL,MESSAGE,SHORTCALLER,THINGID,CATEGORY,PKG,RUNTIME1,RUNTIME2
EOL
$got =~ s/[^\w ,"()]//g; #silly DBD_CSV uses funny EOL chars
$expected =~ s/[^\w ,"()]//g;
$got = lc $got; #accounting for variations in DBD::CSV behavior
$expected = lc $expected;
is($got, $expected, "buffered");
}
$logger->warn('warning message',3456,'foo','bar');
#with buffersize == 2, now they should write
{
local $/ = undef;
open (F, "t/tmp/$table_name");
my $got = <F>;
close F;
my $expected = <<EOL;
LOGLEVEL,MESSAGE,SHORTCALLER,THINGID,CATEGORY,PKG,RUNTIME1,RUNTIME2
FATAL,"fatal message",main:,1234,groceries.beer,main,foo,HASH(0x84cfd64)
WARN,"warning message",main:,3456,groceries.beer,main,foo,bar
EOL
$got =~ s/[^\w ,"()]//g; #silly DBD_CSV uses funny EOL chars
$expected =~ s/[^\w ,"()]//g;
$got =~ s/HASH\(.+?\)//;
$expected =~ s/HASH\(.+?\)//;
$got = lc $got; #accounting for variations in DBD::CSV behavior
$expected = lc $expected;
is($got, $expected, "buffersize=2");
}
# setting is WARN so the debug message should not go through
$logger->debug('debug message',99,'foo','bar');
$logger->warn('warning message with two params',99, 'foo', 'bar');
$logger->warn('another warning to kick the buffer',99, 'foo', 'bar');
my $sth = $dbh->prepare("select * from $table_name");
$sth->execute;
#first two rows are repeats from the last test
my $row = $sth->fetchrow_arrayref;
is($row->[0], 'FATAL');
is($row->[1], 'fatal message');
is($row->[3], '1234');
is($row->[4], 'groceries.beer');
is($row->[5], 'main');
is($row->[6], 'foo');
like($row->[7], qr/HASH/); #verifying param checking for "filter=>sub{...} stuff
$row = $sth->fetchrow_arrayref;
is($row->[0], 'WARN');
is($row->[1], 'warning message');
is($row->[3], '3456');
is($row->[4], 'groceries.beer');
is($row->[5], 'main');
is($row->[6], 'foo');
is($row->[7], 'bar');
#these two rows should have undef for the final two params
$row = $sth->fetchrow_arrayref;
is($row->[0], 'WARN');
is($row->[1], 'warning message with two params');
is($row->[3], '99');
is($row->[4], 'groceries.beer');
is($row->[5], 'main');
is($row->[6], 'foo');
is($row->[7], 'bar');
$row = $sth->fetchrow_arrayref;
is($row->[0], 'WARN');
is($row->[1], 'another warning to kick the buffer');
is($row->[3], '99');
is($row->[4], 'groceries.beer');
is($row->[5], 'main');
is($row->[6], 'foo');
is($row->[7], 'bar');
#that should be all
ok(!$sth->fetchrow_arrayref);
$dbh->disconnect;
# **************************************
# checking usePreparedStmt, spurious warning bug reported by Brett Rann
# might as well give it a thorough check
Log::Log4perl->reset;
unlink "t/tmp/$table_name"
if -e "t/tmp/$table_name";
$dbh = DBI->connect('DBI:CSV:f_dir=t/tmp','testuser','testpw',{ PrintError => 1 });
$stmt = <<EOL;
CREATE TABLE $table_name (
loglevel char(9) ,
message char(128)
)
EOL
$dbh->do($stmt) || die "do failed on $stmt".$dbh->errstr;
$config = <<"EOT";
log4j.category = WARN, DBAppndr
log4j.appender.DBAppndr = Log::Log4perl::Appender::DBI
log4j.appender.DBAppndr.datasource = DBI:CSV:f_dir=t/tmp
log4j.appender.DBAppndr.sql = \\
insert into $table_name \\
(loglevel, message) \\
values (?,?)
log4j.appender.DBAppndr.params.1 = %p
#---------------------------- #2 is message
log4j.appender.DBAppndr.usePreparedStmt=2
log4j.appender.DBAppndr.warp_message=0
#noop layout to pass it through
log4j.appender.DBAppndr.layout = Log::Log4perl::Layout::NoopLayout
EOT
Log::Log4perl::init(\$config);
$logger = Log::Log4perl->get_logger("groceries.beer");
$logger->fatal('warning message');
#since we're not buffering, this message should show up immediately
{
local $/ = undef;
open (F, "t/tmp/$table_name");
my $got = <F>;
close F;
my $expected = <<EOL;
LOGLEVEL,MESSAGE
FATAL,"warning message"
EOL
$got =~ s/[^\w ,"()]//g; #silly DBD_CSV uses funny EOL chars
$expected =~ s/[^\w ,"()]//g;
$got = lc $got; #accounting for variations in DBD::CSV behavior
$expected = lc $expected;
is($got, $expected);
}
$logger->fatal('warning message');
# https://rt.cpan.org/Public/Bug/Display.html?id=79960
# undef as NULL
$dbh->do("DROP TABLE $table_name");
$stmt = <<EOL;
CREATE TABLE $table_name (
loglevel char(9) ,
message char(128),
mdc char(16)
)
EOL
$dbh->do($stmt) || die "do failed on $stmt".$dbh->errstr;
$config = <<"EOT";
log4j.category = WARN, DBAppndr
log4j.appender.DBAppndr = Log::Log4perl::Appender::DBI
log4j.appender.DBAppndr.datasource = DBI:CSV:f_dir=t/tmp
log4j.appender.DBAppndr.sql = \\
insert into $table_name \\
(loglevel, mdc, message) \\
values (?, ?, ?)
log4j.appender.DBAppndr.params.1 = %p
log4j.appender.DBAppndr.params.2 = %X{foo}
#---------------------------- #3 is message
log4j.appender.DBAppndr.usePreparedStmt=2
log4j.appender.DBAppndr.warp_message=0
#noop layout to pass it through
log4j.appender.DBAppndr.layout = Log::Log4perl::Layout::NoopLayout
EOT
Log::Log4perl::init(\$config);
$logger = Log::Log4perl->get_logger();
$logger->warn('test message');
open (F, "t/tmp/$table_name");
my $got = join '', <F>;
close F;
my $expected = <<EOT;
loglevel,message,mdc
WARN,"test message",
EOT
$got =~ s/[^\w ,"()]//g; #silly DBD_CSV uses funny EOL chars
$expected =~ s/[^\w ,"()]//g;
is $got, $expected, "dbi insert with NULL values";