@ -6,15 +6,64 @@ use warnings;
use PostgresNode ;
use TestLib ;
use Test::More tests = > 5 ;
use Test::More tests = > 10 ;
use Time::HiRes qw( usleep ) ;
# Extract the file name of a $format from the contents of
# current_logfiles.
sub fetch_file_name
{
my $ logfiles = shift ;
my $ format = shift ;
my @ lines = split ( /\n/ , $ logfiles ) ;
my $ filename = undef ;
foreach my $ line ( @ lines )
{
if ( $ line =~ /$format (.*)$/gm )
{
$ filename = $ 1 ;
}
}
return $ filename ;
}
# Check for a pattern in the logs associated to one format.
sub check_log_pattern
{
my $ format = shift ;
my $ logfiles = shift ;
my $ pattern = shift ;
my $ node = shift ;
my $ lfname = fetch_file_name ( $ logfiles , $ format ) ;
my $ max_attempts = 180 * 10 ;
my $ logcontents ;
for ( my $ attempts = 0 ; $ attempts < $ max_attempts ; $ attempts + + )
{
$ logcontents = slurp_file ( $ node - > data_dir . '/' . $ lfname ) ;
last if $ logcontents =~ m/$pattern/ ;
usleep ( 100_000 ) ;
}
like ( $ logcontents , qr/$pattern/ ,
"found expected log file content for $format" ) ;
# While we're at it, test pg_current_logfile() function
is ( $ node - > safe_psql ( 'postgres' , "SELECT pg_current_logfile('$format')" ) ,
$ lfname ,
"pg_current_logfile() gives correct answer with $format" ) ;
return ;
}
# Set up node with logging collector
my $ node = PostgresNode - > new ( 'primary' ) ;
$ node - > init ( ) ;
$ node - > append_conf (
'postgresql.conf' , qq(
logging_collector = on
log_destination = 'stderr, csvlog'
# these ensure stability of test results:
log_rotation_age = 0
lc_messages = 'C'
@ -44,26 +93,12 @@ note "current_logfiles = $current_logfiles";
like (
$ current_logfiles ,
qr|^stderr log/postgresql-.*log$| ,
qr | ^ stderr log / postgresql - . * log
csvlog log / postgresql - . * csv $| ,
'current_logfiles is sane' ) ;
my $ lfname = $ current_logfiles ;
$ lfname =~ s/^stderr // ;
chomp $ lfname ;
my $ first_logfile ;
for ( my $ attempts = 0 ; $ attempts < $ max_attempts ; $ attempts + + )
{
$ first_logfile = slurp_file ( $ node - > data_dir . '/' . $ lfname ) ;
last if $ first_logfile =~ m/division by zero/ ;
usleep ( 100_000 ) ;
}
like ( $ first_logfile , qr/division by zero/ , 'found expected log file content' ) ;
# While we're at it, test pg_current_logfile() function
is ( $ node - > safe_psql ( 'postgres' , "SELECT pg_current_logfile('stderr')" ) ,
$ lfname , 'pg_current_logfile() gives correct answer' ) ;
check_log_pattern ( 'stderr' , $ current_logfiles , 'division by zero' , $ node ) ;
check_log_pattern ( 'csvlog' , $ current_logfiles , 'division by zero' , $ node ) ;
# Sleep 2 seconds and ask for log rotation; this should result in
# output into a different log file name.
@ -84,28 +119,14 @@ note "now current_logfiles = $new_current_logfiles";
like (
$ new_current_logfiles ,
qr|^stderr log/postgresql-.*log$| ,
qr | ^ stderr log / postgresql - . * log
csvlog log / postgresql - . * csv $| ,
'new current_logfiles is sane' ) ;
$ lfname = $ new_current_logfiles ;
$ lfname =~ s/^stderr // ;
chomp $ lfname ;
# Verify that log output gets to this file, too
$ node - > psql ( 'postgres' , 'fee fi fo fum' ) ;
my $ second_logfile ;
for ( my $ attempts = 0 ; $ attempts < $ max_attempts ; $ attempts + + )
{
$ second_logfile = slurp_file ( $ node - > data_dir . '/' . $ lfname ) ;
last if $ second_logfile =~ m/syntax error/ ;
usleep ( 100_000 ) ;
}
like (
$ second_logfile ,
qr/syntax error/ ,
'found expected log file content in new log file' ) ;
check_log_pattern ( 'stderr' , $ new_current_logfiles , 'syntax error' , $ node ) ;
check_log_pattern ( 'csvlog' , $ new_current_logfiles , 'syntax error' , $ node ) ;
$ node - > stop ( ) ;