Add regression tests for csvlog with the logging collector

These are added in the existing tests of pg_ctl for log rotation, that
already tested stderr.  The same amount of coverage is added for csvlog:
- Checks for pg_current_logfile().
- Log rotation with expected file name.
- Log contents generated.

This test is refactored to minimize the amount of work required to add
tests for new log formats, easing some upcoming work.

Author: Michael Paquier, Sehrope Sarkuni
Discussion: https://postgr.es/m/CAH7T-aqswBM6JWe4pDehi1uOiufqe06DJWaU5=X7dDLyqUExHg@mail.gmail.com
This commit is contained in:
Michael Paquier 2021-09-13 10:23:59 +09:00
parent 2d77d83540
commit 72b76f7616
1 changed files with 58 additions and 37 deletions

View File

@ -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();