On Mon, Jun 15, 2015 at 8:26 AM, Michael Paquier wrote:
> hamster is legendary slow and has a slow disc, hence it improves
> chances of catching race conditions, and it is the only slow buildfarm
> machine enabling the TAP tests (by comparison dangomushi has never
> failed with the TAP tests) hence I would prefer thinking that the
> problem is not specific to ArchLinux ARM. In this case the failure
> seems to be related to the timing test servers stop and start even if
> -w switch is used with pg_ctl, particularly that PGPORT is set to the
> same value for all servers... Still, for the time being I don't mind
> disabling them and just did so now. I will try to investigate further
> on the machine itself.
So, I have been doing some progress on this thing.. And wrote the
patch attached that improves the way TAP tests log their output using
IPC::Run::run. This simply creates a log file as regress_log/test_name
for each test run, capturing all the command outputs. For example on
current HEAD, some commands of pg_ctl are simply silenced or have
their output redirected to /dev/null. With this patch, all their
output is redirected to the log file. This is as well compatible with
Windows, and logging of pg_rewind tests is unified with the new
structure of TestLib.pm. I am going to apply that to hamster and see
what is causing the error reported.
I think that it would be useful as well to improve the buildfarm
output. Thoughts?
Regards
--
Michael
From b74108a2f3680930df2f9749743cb797d8dbb024 Mon Sep 17 00:00:00 2001
From: Michael Paquier <michael@otacoo.com>
Date: Thu, 18 Jun 2015 15:44:42 +0900
Subject: [PATCH] Improve log capture of TAP tests
All tests have their logs stored as regress_log/$TEST_NAME, with content
captured from the many commands run during the tests.
---
src/Makefile.global.in | 1 +
src/bin/pg_basebackup/.gitignore | 1 +
src/bin/pg_basebackup/Makefile | 2 +-
src/bin/pg_basebackup/t/010_pg_basebackup.pl | 4 +-
src/bin/pg_controldata/.gitignore | 1 +
src/bin/pg_controldata/Makefile | 2 +-
src/bin/pg_controldata/t/001_pg_controldata.pl | 2 +-
src/bin/pg_ctl/.gitignore | 1 +
src/bin/pg_ctl/Makefile | 2 +-
src/bin/pg_ctl/t/001_start_stop.pl | 2 +-
src/bin/pg_ctl/t/002_status.pl | 6 +--
src/bin/pg_rewind/RewindTest.pm | 58 ++++++++++++--------------
src/bin/scripts/.gitignore | 1 +
src/bin/scripts/Makefile | 2 +-
src/test/perl/TestLib.pm | 46 ++++++++++++++------
src/test/ssl/.gitignore | 1 +
src/test/ssl/Makefile | 3 ++
src/test/ssl/ServerSetup.pm | 8 ++--
src/test/ssl/t/001_ssltests.pl | 2 +-
19 files changed, 85 insertions(+), 60 deletions(-)
diff --git a/src/Makefile.global.in b/src/Makefile.global.in
index c583b44..a21aa19 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 -r $(srcdir)/regress_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/.gitignore b/src/bin/pg_basebackup/.gitignore
index 36a2f12..746908b 100644
--- a/src/bin/pg_basebackup/.gitignore
+++ b/src/bin/pg_basebackup/.gitignore
@@ -2,4 +2,5 @@
/pg_receivexlog
/pg_recvlogical
+/regress_log/
/tmp_check/
diff --git a/src/bin/pg_basebackup/Makefile b/src/bin/pg_basebackup/Makefile
index 0d8421a..66771dc 100644
--- a/src/bin/pg_basebackup/Makefile
+++ b/src/bin/pg_basebackup/Makefile
@@ -48,7 +48,7 @@ clean distclean maintainer-clean:
rm -f pg_basebackup$(X) pg_receivexlog$(X) pg_recvlogical$(X) \
pg_basebackup.o pg_receivexlog.o pg_recvlogical.o \
$(OBJS)
- rm -rf tmp_check
+ rm -rf tmp_check regress_log
check:
$(prove_check)
diff --git a/src/bin/pg_basebackup/t/010_pg_basebackup.pl b/src/bin/pg_basebackup/t/010_pg_basebackup.pl
index 3476ea6..ecff372 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', '-s', '-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/.gitignore b/src/bin/pg_controldata/.gitignore
index 051d71d..04d0c68 100644
--- a/src/bin/pg_controldata/.gitignore
+++ b/src/bin/pg_controldata/.gitignore
@@ -1,2 +1,3 @@
/pg_controldata
/tmp_check/
+/regress_log/
diff --git a/src/bin/pg_controldata/Makefile b/src/bin/pg_controldata/Makefile
index fd7399b..3853dd1 100644
--- a/src/bin/pg_controldata/Makefile
+++ b/src/bin/pg_controldata/Makefile
@@ -33,7 +33,7 @@ uninstall:
clean distclean maintainer-clean:
rm -f pg_controldata$(X) $(OBJS)
- rm -rf tmp_check
+ rm -rf tmp_check regress_log
check:
$(prove_check)
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/.gitignore b/src/bin/pg_ctl/.gitignore
index 73ab4ed..3efa15d 100644
--- a/src/bin/pg_ctl/.gitignore
+++ b/src/bin/pg_ctl/.gitignore
@@ -1,2 +1,3 @@
/pg_ctl
/tmp_check/
+/regress_log/
diff --git a/src/bin/pg_ctl/Makefile b/src/bin/pg_ctl/Makefile
index 37eb482..5bce54f 100644
--- a/src/bin/pg_ctl/Makefile
+++ b/src/bin/pg_ctl/Makefile
@@ -36,7 +36,7 @@ uninstall:
clean distclean maintainer-clean:
rm -f pg_ctl$(X) $(OBJS)
- rm -rf tmp_check
+ rm -rf tmp_check regress_log
check:
$(prove_check)
diff --git a/src/bin/pg_ctl/t/001_start_stop.pl b/src/bin/pg_ctl/t/001_start_stop.pl
index 6c9ec5c..511ec48 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', '-s', '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..bfc2147 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', '-s', '-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', '-s', 'stop', '-D', "$tempdir/data", '-m', 'fast']);
diff --git a/src/bin/pg_rewind/RewindTest.pm b/src/bin/pg_rewind/RewindTest.pm
index 5219ec9..c8dff91 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
@@ -175,10 +176,6 @@ 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
@@ -209,8 +206,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 +224,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 +235,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 +256,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 +275,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', '-w', '-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 +295,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', '-w', '-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 +337,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
diff --git a/src/bin/scripts/.gitignore b/src/bin/scripts/.gitignore
index 1056b28..b1647a7 100644
--- a/src/bin/scripts/.gitignore
+++ b/src/bin/scripts/.gitignore
@@ -16,3 +16,4 @@
/print.c
/tmp_check/
+/regress_log/
\ No newline at end of file
diff --git a/src/bin/scripts/Makefile b/src/bin/scripts/Makefile
index c831716..c699470 100644
--- a/src/bin/scripts/Makefile
+++ b/src/bin/scripts/Makefile
@@ -67,7 +67,7 @@ clean distclean maintainer-clean:
rm -f $(addsuffix $(X), $(PROGRAMS)) $(addsuffix .o, $(PROGRAMS))
rm -f common.o dumputils.o kwlookup.o keywords.o print.o mbprint.o $(WIN32RES)
rm -f dumputils.c print.c mbprint.c kwlookup.c keywords.c
- rm -rf tmp_check
+ rm -rf tmp_check regress_log
check:
$(prove_check)
diff --git a/src/test/perl/TestLib.pm b/src/test/perl/TestLib.pm
index ef42366..c00e4df 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,16 @@ our @EXPORT = qw(
);
use Cwd;
+use File::Basename;
use File::Spec;
use File::Temp ();
use IPC::Run qw(run start);
use Test::More;
+mkdir 'regress_log';
+my $test_logfile = basename($0);
+$test_logfile =~ s/\.[^.]+$//;
+$test_logfile = 'regress_log/regress_log_' . $test_logfile;
# Set to untranslated messages, to be able to compare program output
# with expected strings.
@@ -77,9 +84,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 +99,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 +117,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, '-w', '-m',
+ 'immediate', 'stop']);
}
}
@@ -134,6 +141,21 @@ sub system_or_bail
system(@_) == 0 or BAIL_OUT("system @_ 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: $?");
+ }
+}
+
#
# Test functions
diff --git a/src/test/ssl/.gitignore b/src/test/ssl/.gitignore
index a325c2f..d7b2b23 100644
--- a/src/test/ssl/.gitignore
+++ b/src/test/ssl/.gitignore
@@ -1,3 +1,4 @@
# Generated by regression tests
/client-log
/tmp_check/
+/regress_log/
diff --git a/src/test/ssl/Makefile b/src/test/ssl/Makefile
index d9fd29a..785500e 100644
--- a/src/test/ssl/Makefile
+++ b/src/test/ssl/Makefile
@@ -122,5 +122,8 @@ ssl/root+client.crl: ssl/root.crl ssl/client.crl
sslfiles-clean:
rm -f $(SSLFILES) ssl/client_ca.srl ssl/server_ca.srl ssl/client_ca-certindex* ssl/server_ca-certindex* ssl/root_ca-certindex* ssl/root_ca.srl ssl/temp_ca.crt ssl/temp_ca_signed.crt
+clean:
+ rm -rf regress_log
+
check:
$(prove_check)
diff --git a/src/test/ssl/ServerSetup.pm b/src/test/ssl/ServerSetup.pm
index 4ce4a69..16a6ad9 100644
--- a/src/test/ssl/ServerSetup.pm
+++ b/src/test/ssl/ServerSetup.pm
@@ -68,7 +68,7 @@ sub configure_test_server_for_ssl
# Copy all server certificates and keys, and client root cert, to the data dir
copy_files("ssl/server-*.crt", "$tempdir/pgdata");
copy_files("ssl/server-*.key", "$tempdir/pgdata");
- system_or_bail "chmod 0600 '$tempdir'/pgdata/server-*.key";
+ system_or_bail("chmod 0600 $tempdir/pgdata/server-*.key");
copy_files("ssl/root+client_ca.crt", "$tempdir/pgdata");
copy_files("ssl/root+client.crl", "$tempdir/pgdata");
@@ -111,8 +111,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', '-s', '-D', "$tempdir/pgdata", '-w']);
+ run_or_bail(['pg_ctl', 'start', '-s', '-D', "$tempdir/pgdata", '-w']);
}
diff --git a/src/test/ssl/t/001_ssltests.pl b/src/test/ssl/t/001_ssltests.pl
index 926b529..6e84a27 100644
--- a/src/test/ssl/t/001_ssltests.pl
+++ b/src/test/ssl/t/001_ssltests.pl
@@ -78,7 +78,7 @@ sub test_connect_fails
# The client's private key must not be world-readable. Git doesn't track
# permissions (except for the executable bit), so they might be wrong after
# a checkout.
-system_or_bail "chmod 0600 ssl/client.key";
+system_or_bail("chmod 0600 ssl/client.key");
#### Part 0. Set up the server.
--
2.4.3
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
