diff --git a/src/Makefile.global.in b/src/Makefile.global.in index aec6187af6d..d321dc74506 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -322,9 +322,8 @@ cd $(srcdir) && TESTDIR='$(CURDIR)' PATH="$(bindir):$$PATH" PGPORT='6$(DEF_PGPOR endef define prove_check -$(MKDIR_P) tmp_check/log -$(MAKE) -C $(top_builddir) DESTDIR='$(CURDIR)'/tmp_check/install install >'$(CURDIR)'/tmp_check/log/install.log 2>&1 -cd $(srcdir) && TESTDIR='$(CURDIR)' PATH="$(CURDIR)/tmp_check/install$(bindir):$$PATH" $(call add_to_path,$(ld_library_path_var),$(CURDIR)/tmp_check/install$(libdir)) top_builddir='$(CURDIR)/$(top_builddir)' PGPORT='6$(DEF_PGPORT)' $(PROVE) $(PG_PROVE_FLAGS) $(PROVE_FLAGS) t/*.pl +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 else diff --git a/src/bin/pg_basebackup/t/010_pg_basebackup.pl b/src/bin/pg_basebackup/t/010_pg_basebackup.pl index 24a828bb0a3..538ca0aba2c 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 0f62c1439a7..dacdd3e6b38 100644 --- a/src/bin/pg_ctl/t/001_start_stop.pl +++ b/src/bin/pg_ctl/t/001_start_stop.pl @@ -33,4 +33,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 9f84f3849c0..86e810176b6 100644 --- a/src/bin/pg_ctl/t/002_status.pl +++ b/src/bin/pg_ctl/t/002_status.pl @@ -15,9 +15,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/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 003cd9a2cca..37a1bc16208 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. @@ -73,7 +111,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); } @@ -87,14 +125,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"); } @@ -106,28 +145,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 (@_); } @@ -139,24 +195,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); } @@ -165,6 +219,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"); @@ -175,6 +230,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"); @@ -185,7 +241,9 @@ sub program_options_handling_ok { my ($cmd) = @_; my ($stdout, $stderr); - my $result = run [ $cmd, '--not-a-valid-option' ], '>', \$stdout, '2>', \$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"); isnt($stderr, '', "$cmd with invalid option prints error message"); } @@ -194,6 +252,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"); @@ -203,9 +262,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");