diff --git a/src/Makefile.global.in b/src/Makefile.global.in index 8eab178ebd3..8d1250d3648 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -337,6 +337,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 c8c9250b384..e47c3a0bb7c 100644 --- a/src/bin/pg_basebackup/t/010_pg_basebackup.pl +++ b/src/bin/pg_basebackup/t/010_pg_basebackup.pl @@ -30,7 +30,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'; +system_or_bail 'pg_ctl', '-D', "$tempdir/pgdata", 'reload'; command_fails( [ 'pg_basebackup', '-D', "$tempdir/backup" ], diff --git a/src/bin/pg_controldata/t/001_pg_controldata.pl b/src/bin/pg_controldata/t/001_pg_controldata.pl index a4180e7ed18..e36fa2d45d9 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"; +system_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 6c9ec5c717a..bcceb57d7bc 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'; +system_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 055885495ab..ec0a2a786e0 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', +system_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'; +system_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 9ade7efcce4..79ddca3eec9 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 7d607157e38..92b5d20afa7 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 5219ec967ae..e57b41734df 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\""); + system_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\""); + system_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,9 +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" - ); + system_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 # up standby @@ -225,8 +217,8 @@ 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"); + system_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,9 +227,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" - ); + system_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 # pg_stat_replication. @@ -255,8 +247,7 @@ 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"); + system_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 +265,7 @@ 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"); + system_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. @@ -291,35 +281,24 @@ sub run_pg_rewind # Now run pg_rewind if ($test_mode eq "local") { - # 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" - ); - my $result = run( - [ 'pg_rewind', - "--debug", - "--source-pgdata=$test_standby_datadir", - "--target-pgdata=$test_master_datadir" ], - '>>', - $log_path, - '2>&1'); - ok($result, 'pg_rewind local'); + system_or_bail('pg_ctl', '-D', $test_standby_datadir, 'stop', + '-m', 'fast'); + command_ok(['pg_rewind', + "--debug", + "--source-pgdata=$test_standby_datadir", + "--target-pgdata=$test_master_datadir"], + 'pg_rewind local'); } elsif ($test_mode eq "remote") { - # Do rewind using a remote connection as source - my $result = run( - [ 'pg_rewind', - "--source-server", - "port=$port_standby dbname=postgres", - "--target-pgdata=$test_master_datadir" ], - '>>', - $log_path, - '2>&1'); - ok($result, 'pg_rewind remote'); + command_ok(['pg_rewind', + "--source-server", + "port=$port_standby dbname=postgres", + "--target-pgdata=$test_master_datadir"], + 'pg_rewind remote'); } else { @@ -342,9 +321,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" - ); + system_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 } @@ -355,12 +334,12 @@ sub clean_rewind_test if ($test_master_datadir) { system - "pg_ctl -D $test_master_datadir -s -m immediate stop 2> /dev/null"; + '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"; + '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 f60368bd307..be7d887bb7c 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 7564fa98a53..b0b007a763a 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 9a952685be9..0cd0ac4d567 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/SimpleTee.pm b/src/test/perl/SimpleTee.pm new file mode 100644 index 00000000000..8d31a4013c8 --- /dev/null +++ b/src/test/perl/SimpleTee.pm @@ -0,0 +1,27 @@ +# A simple 'tee' implementation, using perl tie. +# +# Whenever you print to the handle, it gets forwarded to a list of +# handles. The list of output filehandles is passed to the constructor. +# +# This is similar to IO::Tee, but only used for output. Only the PRINT +# method is currently implemented; that's all we need. We don't want to +# depend on IO::Tee just for this. + +package SimpleTee; +use strict; + +sub TIEHANDLE { + my $self = shift; + bless \@_, $self; +} + +sub PRINT { + my $self = shift; + my $ok = 1; + for my $fh (@$self) { + print $fh @_ or $ok = 0; + } + return $ok; +} + +1; diff --git a/src/test/perl/TestLib.pm b/src/test/perl/TestLib.pm index ef42366888e..0193d575ff7 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 + system_log + run_log command_ok command_fails @@ -24,11 +26,47 @@ our @EXPORT = qw( ); use Cwd; +use File::Basename; use File::Spec; use File::Temp (); use IPC::Run qw(run start); + +use SimpleTee; + use Test::More; +# Open log file. For each test, the log file name uses the name of the +# file launching this module, without the .pl suffix. +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"; +open TESTLOG, '>', $test_logfile or die "Cannot open STDOUT to logfile: $!"; + +# Hijack STDOUT and STDERR to the log file +open(ORIG_STDOUT, ">&STDOUT"); +open(ORIG_STDERR, ">&STDERR"); +open(STDOUT, ">&TESTLOG"); +open(STDERR, ">&TESTLOG"); + +# The test output (ok ...) needs to be printed to the original STDOUT so +# that the 'prove' program can parse it, and display it to the user in +# real time. But also copy it to the log file, to provide more context +# in the log. +my $builder = Test::More->builder; +my $fh = $builder->output; +tie *$fh, "SimpleTee", *ORIG_STDOUT, *TESTLOG; +$fh = $builder->failure_output; +tie *$fh, "SimpleTee", *ORIG_STDERR, *TESTLOG; + +# Enable auto-flushing for all the file handles. Stderr and stdout are +# redirected to the same file, and buffering causes the lines to appear +# in the log in confusing order. +autoflush STDOUT 1; +autoflush STDERR 1; +autoflush TESTLOG 1; # Set to untranslated messages, to be able to compare program output # with expected strings. @@ -77,7 +115,7 @@ sub tempdir_short sub standard_initdb { my $pgdata = shift; - system_or_bail("initdb -D '$pgdata' -A trust -N >/dev/null"); + system_or_bail('initdb', '-D', "$pgdata", '-A' , 'trust', '-N'); system_or_bail("$ENV{top_builddir}/src/test/regress/pg_regress", '--config-auth', $pgdata); } @@ -91,14 +129,15 @@ sub start_test_server my $tempdir_short = tempdir_short; + print("### Starting test server in $tempdir\n"); standard_initdb "$tempdir/pgdata"; - $ret = system 'pg_ctl', '-D', "$tempdir/pgdata", '-s', '-w', '-l', + $ret = system_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) { + print "# pg_ctl failed; logfile:\n"; system('cat', "$tempdir/logfile"); BAIL_OUT("pg_ctl failed"); } @@ -110,28 +149,45 @@ sub start_test_server sub restart_test_server { - system 'pg_ctl', '-s', '-D', $test_server_datadir, '-w', '-l', - $test_server_logfile, 'restart'; + print("### Restarting test server\n"); + system_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'; + system_log('pg_ctl', '-D', $test_server_datadir, '-m', + 'immediate', 'stop'); } } sub psql { my ($dbname, $sql) = @_; + print("# Running SQL command: $sql\n"); run [ 'psql', '-X', '-q', '-d', $dbname, '-f', '-' ], '<', \$sql or die; } sub system_or_bail { - system(@_) == 0 or BAIL_OUT("system @_ failed: $?"); + if (system_log(@_) != 0) + { + BAIL_OUT("system $_[0] failed: $?"); + } +} + +sub system_log +{ + print("# Running: " . join(" ", @_) ."\n"); + return system(@_); +} + +sub run_log +{ + print("# Running: " . join(" ", @{$_[0]}) ."\n"); + return run (@_); } @@ -143,24 +199,22 @@ sub system_or_bail sub command_ok { my ($cmd, $test_name) = @_; - my $result = run $cmd, '>', File::Spec->devnull(), '2>', - File::Spec->devnull(); + my $result = run_log($cmd); ok($result, $test_name); } sub command_fails { my ($cmd, $test_name) = @_; - my $result = run $cmd, '>', File::Spec->devnull(), '2>', - File::Spec->devnull(); + my $result = run_log($cmd); ok(!$result, $test_name); } sub command_exit_is { my ($cmd, $expected, $test_name) = @_; - my $h = start $cmd, '>', File::Spec->devnull(), '2>', - File::Spec->devnull(); + print("# Running: " . join(" ", @{$cmd}) ."\n"); + my $h = start $cmd; $h->finish(); is($h->result(0), $expected, $test_name); } @@ -169,6 +223,7 @@ sub program_help_ok { my ($cmd) = @_; my ($stdout, $stderr); + print("# Running: $cmd --help\n"); my $result = run [ $cmd, '--help' ], '>', \$stdout, '2>', \$stderr; ok($result, "$cmd --help exit code 0"); isnt($stdout, '', "$cmd --help goes to stdout"); @@ -179,6 +234,7 @@ sub program_version_ok { my ($cmd) = @_; my ($stdout, $stderr); + print("# Running: $cmd --version\n"); my $result = run [ $cmd, '--version' ], '>', \$stdout, '2>', \$stderr; ok($result, "$cmd --version exit code 0"); isnt($stdout, '', "$cmd --version goes to stdout"); @@ -189,6 +245,7 @@ sub program_options_handling_ok { my ($cmd) = @_; my ($stdout, $stderr); + print("# Running: $cmd --not-a-valid-option\n"); my $result = run [ $cmd, '--not-a-valid-option' ], '>', \$stdout, '2>', \$stderr; ok(!$result, "$cmd with invalid option nonzero exit code"); @@ -199,6 +256,7 @@ sub command_like { my ($cmd, $expected_stdout, $test_name) = @_; my ($stdout, $stderr); + print("# Running: " . join(" ", @{$cmd}) . "\n"); my $result = run $cmd, '>', \$stdout, '2>', \$stderr; ok($result, "@$cmd exit code 0"); is($stderr, '', "@$cmd no stderr"); @@ -208,9 +266,8 @@ sub command_like sub issues_sql_like { my ($cmd, $expected_sql, $test_name) = @_; - my ($stdout, $stderr); truncate $test_server_logfile, 0; - my $result = run $cmd, '>', \$stdout, '2>', \$stderr; + my $result = run_log($cmd); ok($result, "@$cmd exit code 0"); my $log = `cat '$test_server_logfile'`; like($log, $expected_sql, "$test_name: SQL found in server log"); diff --git a/src/test/ssl/ServerSetup.pm b/src/test/ssl/ServerSetup.pm index bbff99a3bdb..8c1b5175755 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"; + system_or_bail 'pg_ctl', 'stop', '-D', "$tempdir/pgdata"; + system_or_bail 'pg_ctl', 'start', '-D', "$tempdir/pgdata", '-w'; }