On Sat, Jun 20, 2015 at 7:06 AM, Michael Paquier
<michael.paqu...@gmail.com> wrote:
>> As far as the
>> rest of this patch goes, it seems like it could be made less invasive
>> if the logs got dumped into a subdirectory of tmp_check rather than
>> adding another top-level directory that has to be cleaned?
>
> tmp_check remains unused since dcae5fac (missing something perhaps?),
> but I guess we could use it again to save the logs in it, and have
> pg_rewind do the same.
OK, so here is an updated patch. All the logs are saved in
tmp_check/log, and each log file is named with the name of the file
that launched the test to facilitate its identification. I noticed at
the same time that some commands were called in silent mode. I removed
that and now what they output is written as well in the log files.
Regards,
--
Michael
From 59fa3c2cd99bfbff970c6054ea279bb26a0a3413 Mon Sep 17 00:00:00 2001
From: Michael Paquier <michael@otacoo.com>
Date: Sat, 20 Jun 2015 17:44:39 +0900
Subject: [PATCH] Improve log capture of TAP tests and fix race conditions
All tests have their logs stored as regress_log/$TEST_NAME, with content
captured from the many commands run during the tests. Commands that were
previously called in silent mode are made verbose and have their output
written in the newly-created log files.
---
src/Makefile.global.in | 1 +
src/bin/pg_basebackup/t/010_pg_basebackup.pl | 4 +-
src/bin/pg_controldata/t/001_pg_controldata.pl | 2 +-
src/bin/pg_ctl/t/001_start_stop.pl | 2 +-
src/bin/pg_ctl/t/002_status.pl | 6 +--
src/bin/pg_rewind/.gitignore | 1 -
src/bin/pg_rewind/Makefile | 2 +-
src/bin/pg_rewind/RewindTest.pm | 74 ++++++++++++--------------
src/bin/pg_rewind/t/001_basic.pl | 1 -
src/bin/pg_rewind/t/002_databases.pl | 1 -
src/bin/pg_rewind/t/003_extrafiles.pl | 1 -
src/test/perl/TestLib.pm | 52 +++++++++++++-----
src/test/ssl/ServerSetup.pm | 6 +--
13 files changed, 83 insertions(+), 70 deletions(-)
diff --git a/src/Makefile.global.in b/src/Makefile.global.in
index c583b44..171d1e4 100644
--- a/src/Makefile.global.in
+++ b/src/Makefile.global.in
@@ -336,6 +336,7 @@ cd $(srcdir) && TESTDIR='$(CURDIR)' PATH="$(bindir):$$PATH" PGPORT='6$(DEF_PGPOR
endef
define prove_check
+rm -rf $(srcdir)/tmp_check/log
cd $(srcdir) && TESTDIR='$(CURDIR)' $(with_temp_install) PGPORT='6$(DEF_PGPORT)' top_builddir='$(CURDIR)/$(top_builddir)' $(PROVE) $(PG_PROVE_FLAGS) $(PROVE_FLAGS) t/*.pl
endef
diff --git a/src/bin/pg_basebackup/t/010_pg_basebackup.pl b/src/bin/pg_basebackup/t/010_pg_basebackup.pl
index 3476ea6..b87ef29 100644
--- a/src/bin/pg_basebackup/t/010_pg_basebackup.pl
+++ b/src/bin/pg_basebackup/t/010_pg_basebackup.pl
@@ -22,7 +22,7 @@ print HBA "local replication all trust\n";
print HBA "host replication all 127.0.0.1/32 trust\n";
print HBA "host replication all ::1/128 trust\n";
close HBA;
-system_or_bail 'pg_ctl', '-s', '-D', "$tempdir/pgdata", 'reload';
+run_or_bail(['pg_ctl', '-D', "$tempdir/pgdata", 'reload']);
command_fails(
[ 'pg_basebackup', '-D', "$tempdir/backup" ],
@@ -51,7 +51,7 @@ ok(-f "$tempdir/tarbackup/base.tar", 'backup tar was created');
my $superlongname = "superlongname_" . ("x" x 100);
-system_or_bail 'touch', "$tempdir/pgdata/$superlongname";
+run_or_bail(['touch', "$tempdir/pgdata/$superlongname"]);
command_fails([ 'pg_basebackup', '-D', "$tempdir/tarbackup_l1", '-Ft' ],
'pg_basebackup tar with long name fails');
unlink "$tempdir/pgdata/$superlongname";
diff --git a/src/bin/pg_controldata/t/001_pg_controldata.pl b/src/bin/pg_controldata/t/001_pg_controldata.pl
index a4180e7..0d1407e 100644
--- a/src/bin/pg_controldata/t/001_pg_controldata.pl
+++ b/src/bin/pg_controldata/t/001_pg_controldata.pl
@@ -11,6 +11,6 @@ program_options_handling_ok('pg_controldata');
command_fails(['pg_controldata'], 'pg_controldata without arguments fails');
command_fails([ 'pg_controldata', 'nonexistent' ],
'pg_controldata with nonexistent directory fails');
-system_or_bail "initdb -D '$tempdir'/data -A trust >/dev/null";
+run_or_bail(['initdb', '-D', "$tempdir/data", '-A', 'trust']);
command_like([ 'pg_controldata', "$tempdir/data" ],
qr/checkpoint/, 'pg_controldata produces output');
diff --git a/src/bin/pg_ctl/t/001_start_stop.pl b/src/bin/pg_ctl/t/001_start_stop.pl
index 6c9ec5c..57563d7 100644
--- a/src/bin/pg_ctl/t/001_start_stop.pl
+++ b/src/bin/pg_ctl/t/001_start_stop.pl
@@ -36,4 +36,4 @@ command_ok([ 'pg_ctl', 'restart', '-D', "$tempdir/data", '-w', '-m', 'fast' ],
command_ok([ 'pg_ctl', 'restart', '-D', "$tempdir/data", '-w', '-m', 'fast' ],
'pg_ctl restart with server running');
-system_or_bail 'pg_ctl', '-s', 'stop', '-D', "$tempdir/data", '-m', 'fast';
+run_or_bail(['pg_ctl', 'stop', '-D', "$tempdir/data", '-m', 'fast']);
diff --git a/src/bin/pg_ctl/t/002_status.pl b/src/bin/pg_ctl/t/002_status.pl
index 0558854..d1192f6 100644
--- a/src/bin/pg_ctl/t/002_status.pl
+++ b/src/bin/pg_ctl/t/002_status.pl
@@ -18,9 +18,9 @@ close CONF;
command_exit_is([ 'pg_ctl', 'status', '-D', "$tempdir/data" ],
3, 'pg_ctl status with server not running');
-system_or_bail 'pg_ctl', '-s', '-l', "$tempdir/logfile", '-D',
- "$tempdir/data", '-w', 'start';
+run_or_bail(['pg_ctl', '-l', "$tempdir/logfile", '-D',
+ "$tempdir/data", '-w', 'start']);
command_exit_is([ 'pg_ctl', 'status', '-D', "$tempdir/data" ],
0, 'pg_ctl status with server running');
-system_or_bail 'pg_ctl', '-s', 'stop', '-D', "$tempdir/data", '-m', 'fast';
+run_or_bail(['pg_ctl', 'stop', '-D', "$tempdir/data", '-m', 'fast']);
diff --git a/src/bin/pg_rewind/.gitignore b/src/bin/pg_rewind/.gitignore
index 9ade7ef..79ddca3 100644
--- a/src/bin/pg_rewind/.gitignore
+++ b/src/bin/pg_rewind/.gitignore
@@ -4,4 +4,3 @@
# Generated by test suite
/tmp_check/
-/regress_log/
diff --git a/src/bin/pg_rewind/Makefile b/src/bin/pg_rewind/Makefile
index 7d60715..92b5d20 100644
--- a/src/bin/pg_rewind/Makefile
+++ b/src/bin/pg_rewind/Makefile
@@ -45,7 +45,7 @@ uninstall:
clean distclean maintainer-clean:
rm -f pg_rewind$(X) $(OBJS) xlogreader.c
- rm -rf tmp_check regress_log
+ rm -rf tmp_check
check:
$(prove_check)
diff --git a/src/bin/pg_rewind/RewindTest.pm b/src/bin/pg_rewind/RewindTest.pm
index 5219ec9..814bffa 100644
--- a/src/bin/pg_rewind/RewindTest.pm
+++ b/src/bin/pg_rewind/RewindTest.pm
@@ -79,7 +79,6 @@ mkdir "regress_log";
my $port_master = $ENV{PGPORT};
my $port_standby = $port_master + 1;
-my $log_path;
my $tempdir_short;
my $connstr_master = "port=$port_master";
@@ -91,14 +90,16 @@ sub master_psql
{
my $cmd = shift;
- system_or_bail("psql -q --no-psqlrc -d $connstr_master -c \"$cmd\"");
+ run_or_bail(['psql', '-q', '--no-psqlrc', '-d', $connstr_master,
+ '-c', "$cmd"]);
}
sub standby_psql
{
my $cmd = shift;
- system_or_bail("psql -q --no-psqlrc -d $connstr_standby -c \"$cmd\"");
+ run_or_bail(['psql', '-q', '--no-psqlrc', '-d', $connstr_standby,
+ '-c', "$cmd"]);
}
# Run a query against the master, and check that the output matches what's
@@ -171,16 +172,6 @@ sub append_to_file
close $fh;
}
-sub init_rewind_test
-{
- my $testname = shift;
- my $test_mode = shift;
-
- $log_path = "regress_log/pg_rewind_log_${testname}_${test_mode}";
-
- remove_tree $log_path;
-}
-
sub setup_cluster
{
$tempdir_short = tempdir_short;
@@ -209,8 +200,10 @@ max_connections = 10
local replication all trust
));
- system_or_bail(
-"pg_ctl -w -D $test_master_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_master\" start >>$log_path 2>&1"
+ run_or_bail(
+ ['pg_ctl' , '-w', '-D' , $test_master_datadir,
+ "-o", "-k $tempdir_short --listen-addresses='' -p $port_master",
+ 'start']
);
#### Now run the test-specific parts to initialize the master before setting
@@ -225,8 +218,9 @@ sub create_standby
remove_tree $test_standby_datadir;
# Base backup is taken with xlog files included
- system_or_bail(
-"pg_basebackup -D $test_standby_datadir -p $port_master -x >>$log_path 2>&1");
+ run_or_bail(
+ ['pg_basebackup', '-D', $test_standby_datadir, '-p',
+ $port_master, '-x']);
append_to_file(
"$test_standby_datadir/recovery.conf", qq(
primary_conninfo='$connstr_master application_name=rewind_standby'
@@ -235,8 +229,9 @@ recovery_target_timeline='latest'
));
# Start standby
- system_or_bail(
-"pg_ctl -w -D $test_standby_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_standby\" start >>$log_path 2>&1"
+ run_or_bail(
+ ['pg_ctl', '-w', '-D', $test_standby_datadir , '-o',
+ "-k $tempdir_short --listen-addresses='' -p $port_standby", 'start']
);
# Wait until the standby has caught up with the primary, by polling
@@ -255,8 +250,8 @@ sub promote_standby
# Now promote slave and insert some new data on master, this will put
# the master out-of-sync with the standby. Wait until the standby is
# out of recovery mode, and is ready to accept read-write connections.
- system_or_bail(
- "pg_ctl -w -D $test_standby_datadir promote >>$log_path 2>&1");
+ run_or_bail(
+ ['pg_ctl', '-w', '-D', $test_standby_datadir, 'promote']);
poll_query_until("SELECT NOT pg_is_in_recovery()", $connstr_standby)
or die "Timed out while waiting for promotion of standby";
@@ -274,8 +269,8 @@ sub run_pg_rewind
my $test_mode = shift;
# Stop the master and be ready to perform the rewind
- system_or_bail(
- "pg_ctl -w -D $test_master_datadir stop -m fast >>$log_path 2>&1");
+ run_or_bail(
+ ['pg_ctl', '-D', $test_master_datadir, 'stop', '-m', 'fast']);
# At this point, the rewind processing is ready to run.
# We now have a very simple scenario with a few diverged WAL record.
@@ -294,31 +289,25 @@ sub run_pg_rewind
# Do rewind using a local pgdata as source
# Stop the master and be ready to perform the rewind
- system_or_bail(
- "pg_ctl -w -D $test_standby_datadir stop -m fast >>$log_path 2>&1"
+ run_or_bail(
+ ['pg_ctl', '-D', $test_standby_datadir, 'stop', '-m', 'fast']
);
- my $result = run(
+ my $result = run_log(
[ 'pg_rewind',
"--debug",
"--source-pgdata=$test_standby_datadir",
- "--target-pgdata=$test_master_datadir" ],
- '>>',
- $log_path,
- '2>&1');
+ "--target-pgdata=$test_master_datadir" ]);
ok($result, 'pg_rewind local');
}
elsif ($test_mode eq "remote")
{
# Do rewind using a remote connection as source
- my $result = run(
+ my $result = run_log(
[ 'pg_rewind',
"--source-server",
"port=$port_standby dbname=postgres",
- "--target-pgdata=$test_master_datadir" ],
- '>>',
- $log_path,
- '2>&1');
+ "--target-pgdata=$test_master_datadir" ]);
ok($result, 'pg_rewind remote');
}
else
@@ -342,8 +331,9 @@ recovery_target_timeline='latest'
));
# Restart the master to check that rewind went correctly
- system_or_bail(
-"pg_ctl -w -D $test_master_datadir -o \"-k $tempdir_short --listen-addresses='' -p $port_master\" start >>$log_path 2>&1"
+ run_or_bail(
+ ['pg_ctl', '-w', '-D', $test_master_datadir, '-o',
+ "-k $tempdir_short --listen-addresses='' -p $port_master", 'start']
);
#### Now run the test-specific parts to check the result
@@ -354,13 +344,15 @@ sub clean_rewind_test
{
if ($test_master_datadir)
{
- system
- "pg_ctl -D $test_master_datadir -s -m immediate stop 2> /dev/null";
+ run_log(
+ ['pg_ctl', '-D', $test_master_datadir, '-m', 'immediate',
+ 'stop']);
}
if ($test_standby_datadir)
{
- system
- "pg_ctl -D $test_standby_datadir -s -m immediate stop 2> /dev/null";
+ run_log(
+ ['pg_ctl', '-D', $test_standby_datadir, '-m', 'immediate',
+ 'stop']);
}
}
diff --git a/src/bin/pg_rewind/t/001_basic.pl b/src/bin/pg_rewind/t/001_basic.pl
index f60368b..be7d887 100644
--- a/src/bin/pg_rewind/t/001_basic.pl
+++ b/src/bin/pg_rewind/t/001_basic.pl
@@ -9,7 +9,6 @@ sub run_test
{
my $test_mode = shift;
- RewindTest::init_rewind_test('basic', $test_mode);
RewindTest::setup_cluster();
# Create a test table and insert a row in master.
diff --git a/src/bin/pg_rewind/t/002_databases.pl b/src/bin/pg_rewind/t/002_databases.pl
index 7564fa9..b0b007a 100644
--- a/src/bin/pg_rewind/t/002_databases.pl
+++ b/src/bin/pg_rewind/t/002_databases.pl
@@ -9,7 +9,6 @@ sub run_test
{
my $test_mode = shift;
- RewindTest::init_rewind_test('databases', $test_mode);
RewindTest::setup_cluster();
# Create a database in master.
diff --git a/src/bin/pg_rewind/t/003_extrafiles.pl b/src/bin/pg_rewind/t/003_extrafiles.pl
index 9a95268..0cd0ac4 100644
--- a/src/bin/pg_rewind/t/003_extrafiles.pl
+++ b/src/bin/pg_rewind/t/003_extrafiles.pl
@@ -14,7 +14,6 @@ sub run_test
{
my $test_mode = shift;
- RewindTest::init_rewind_test('extrafiles', $test_mode);
RewindTest::setup_cluster();
my $test_master_datadir = $RewindTest::test_master_datadir;
diff --git a/src/test/perl/TestLib.pm b/src/test/perl/TestLib.pm
index ef42366..98fefce 100644
--- a/src/test/perl/TestLib.pm
+++ b/src/test/perl/TestLib.pm
@@ -12,6 +12,8 @@ our @EXPORT = qw(
restart_test_server
psql
system_or_bail
+ run_or_bail
+ run_log
command_ok
command_fails
@@ -24,11 +26,20 @@ our @EXPORT = qw(
);
use Cwd;
+use File::Basename;
use File::Spec;
use File::Temp ();
use IPC::Run qw(run start);
use Test::More;
+# Log file location. For each test, the log file name uses the name of the
+# file launching this module, without its file prefix for readability.
+my $log_path = 'tmp_check/log';
+mkdir 'tmp_check';
+mkdir $log_path;
+my $test_logfile = basename($0);
+$test_logfile =~ s/\.[^.]+$//;
+$test_logfile = "$log_path/regress_log_$test_logfile";
# Set to untranslated messages, to be able to compare program output
# with expected strings.
@@ -77,9 +88,9 @@ sub tempdir_short
sub standard_initdb
{
my $pgdata = shift;
- system_or_bail("initdb -D '$pgdata' -A trust -N >/dev/null");
- system_or_bail("$ENV{top_builddir}/src/test/regress/pg_regress",
- '--config-auth', $pgdata);
+ run_or_bail(['initdb', '-D', "$pgdata", '-A' , 'trust', '-N']);
+ run_or_bail(["$ENV{top_builddir}/src/test/regress/pg_regress",
+ '--config-auth', $pgdata]);
}
my ($test_server_datadir, $test_server_logfile);
@@ -92,14 +103,14 @@ sub start_test_server
my $tempdir_short = tempdir_short;
standard_initdb "$tempdir/pgdata";
- $ret = system 'pg_ctl', '-D', "$tempdir/pgdata", '-s', '-w', '-l',
+ $ret = run_log(['pg_ctl', '-D', "$tempdir/pgdata", '-w', '-l',
"$tempdir/logfile", '-o',
-"--fsync=off -k $tempdir_short --listen-addresses='' --log-statement=all",
- 'start';
+"--fsync=off -k \"$tempdir_short\" --listen-addresses='' --log-statement=all",
+ 'start']);
- if ($ret != 0)
+ if (!$ret)
{
- system('cat', "$tempdir/logfile");
+ run_log(['cat', "$tempdir/logfile"]);
BAIL_OUT("pg_ctl failed");
}
@@ -110,16 +121,16 @@ sub start_test_server
sub restart_test_server
{
- system 'pg_ctl', '-s', '-D', $test_server_datadir, '-w', '-l',
- $test_server_logfile, 'restart';
+ run_log(['pg_ctl', '-D', $test_server_datadir, '-w', '-l',
+ $test_server_logfile, 'restart']);
}
END
{
if ($test_server_datadir)
{
- system 'pg_ctl', '-D', $test_server_datadir, '-s', '-w', '-m',
- 'immediate', 'stop';
+ run_log(['pg_ctl', '-D', $test_server_datadir, '-m',
+ 'immediate', 'stop']);
}
}
@@ -131,7 +142,22 @@ sub psql
sub system_or_bail
{
- system(@_) == 0 or BAIL_OUT("system @_ failed: $?");
+ system(@_) == 0 or BAIL_OUT("system $_[0] failed: $?");
+}
+
+sub run_log
+{
+ my $result = run (@_, '>>', $test_logfile, '2>&1');
+ return $result;
+}
+
+sub run_or_bail
+{
+ my $result = run (@_, '>>', $test_logfile, '2>&1');
+ if (!$result)
+ {
+ BAIL_OUT("run $_[0] failed: $?");
+ }
}
diff --git a/src/test/ssl/ServerSetup.pm b/src/test/ssl/ServerSetup.pm
index bbff99a..2293d1b 100644
--- a/src/test/ssl/ServerSetup.pm
+++ b/src/test/ssl/ServerSetup.pm
@@ -125,8 +125,6 @@ sub switch_server_cert
# restart_test_server() because that overrides listen_addresses to only all
# Unix domain socket connections.
- system_or_bail 'pg_ctl', 'stop', '-s', '-D', "$tempdir/pgdata", '-w';
- system_or_bail 'pg_ctl', 'start', '-s', '-D', "$tempdir/pgdata", '-w',
- '-l',
- "$tempdir/logfile";
+ run_or_bail(['pg_ctl', 'stop', '-D', "$tempdir/pgdata"]);
+ run_or_bail(['pg_ctl', 'start', '-D', "$tempdir/pgdata", '-w']);
}
--
2.4.4
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
