mirror of
				https://github.com/postgres/postgres.git
				synced 2025-11-03 09:13:20 +03:00 
			
		
		
		
	Introduce PG_TEST_TIMEOUT_DEFAULT for TAP suite non-elapsing timeouts.
Slow hosts may avoid load-induced, spurious failures by setting environment variable PG_TEST_TIMEOUT_DEFAULT to some number of seconds greater than 180. Developers may see faster failures by setting that environment variable to some lesser number of seconds. In tests, write $PostgreSQL::Test::Utils::timeout_default wherever the convention has been to write 180. This change raises the default for some briefer timeouts. Back-patch to v10 (all supported versions). Discussion: https://postgr.es/m/20220218052842.GA3627003@rfd.leadboat.com
This commit is contained in:
		@@ -18,7 +18,8 @@ my ($node, $result);
 | 
				
			|||||||
#
 | 
					#
 | 
				
			||||||
$node = get_new_node('CIC_test');
 | 
					$node = get_new_node('CIC_test');
 | 
				
			||||||
$node->init;
 | 
					$node->init;
 | 
				
			||||||
$node->append_conf('postgresql.conf', 'lock_timeout = 180000');
 | 
					$node->append_conf('postgresql.conf',
 | 
				
			||||||
 | 
						'lock_timeout = ' . (1000 * $TestLib::timeout_default));
 | 
				
			||||||
$node->start;
 | 
					$node->start;
 | 
				
			||||||
$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
 | 
					$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
 | 
				
			||||||
$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 | 
					$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -22,7 +22,8 @@ my ($node, $result);
 | 
				
			|||||||
$node = get_new_node('CIC_2PC_test');
 | 
					$node = get_new_node('CIC_2PC_test');
 | 
				
			||||||
$node->init;
 | 
					$node->init;
 | 
				
			||||||
$node->append_conf('postgresql.conf', 'max_prepared_transactions = 10');
 | 
					$node->append_conf('postgresql.conf', 'max_prepared_transactions = 10');
 | 
				
			||||||
$node->append_conf('postgresql.conf', 'lock_timeout = 180000');
 | 
					$node->append_conf('postgresql.conf',
 | 
				
			||||||
 | 
						'lock_timeout = ' . (1000 * $TestLib::timeout_default));
 | 
				
			||||||
$node->start;
 | 
					$node->start;
 | 
				
			||||||
$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
 | 
					$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
 | 
				
			||||||
$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 | 
					$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 | 
				
			||||||
@@ -38,7 +39,7 @@ $node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 | 
				
			|||||||
 | 
					
 | 
				
			||||||
my $main_in    = '';
 | 
					my $main_in    = '';
 | 
				
			||||||
my $main_out   = '';
 | 
					my $main_out   = '';
 | 
				
			||||||
my $main_timer = IPC::Run::timeout(180);
 | 
					my $main_timer = IPC::Run::timeout($TestLib::timeout_default);
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $main_h =
 | 
					my $main_h =
 | 
				
			||||||
  $node->background_psql('postgres', \$main_in, \$main_out,
 | 
					  $node->background_psql('postgres', \$main_in, \$main_out,
 | 
				
			||||||
@@ -52,7 +53,7 @@ pump $main_h until $main_out =~ /syncpoint1/ || $main_timer->is_expired;
 | 
				
			|||||||
 | 
					
 | 
				
			||||||
my $cic_in    = '';
 | 
					my $cic_in    = '';
 | 
				
			||||||
my $cic_out   = '';
 | 
					my $cic_out   = '';
 | 
				
			||||||
my $cic_timer = IPC::Run::timeout(180);
 | 
					my $cic_timer = IPC::Run::timeout($TestLib::timeout_default);
 | 
				
			||||||
my $cic_h =
 | 
					my $cic_h =
 | 
				
			||||||
  $node->background_psql('postgres', \$cic_in, \$cic_out,
 | 
					  $node->background_psql('postgres', \$cic_in, \$cic_out,
 | 
				
			||||||
	$cic_timer, on_error_stop => 1);
 | 
						$cic_timer, on_error_stop => 1);
 | 
				
			||||||
@@ -113,9 +114,10 @@ PREPARE TRANSACTION 'persists_forever';
 | 
				
			|||||||
));
 | 
					));
 | 
				
			||||||
$node->restart;
 | 
					$node->restart;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $reindex_in    = '';
 | 
					my $reindex_in  = '';
 | 
				
			||||||
my $reindex_out   = '';
 | 
					my $reindex_out = '';
 | 
				
			||||||
my $reindex_timer = IPC::Run::timeout(180);
 | 
					my $reindex_timer =
 | 
				
			||||||
 | 
					  IPC::Run::timeout($TestLib::timeout_default);
 | 
				
			||||||
my $reindex_h =
 | 
					my $reindex_h =
 | 
				
			||||||
  $node->background_psql('postgres', \$reindex_in, \$reindex_out,
 | 
					  $node->background_psql('postgres', \$reindex_in, \$reindex_out,
 | 
				
			||||||
	$reindex_timer, on_error_stop => 1);
 | 
						$reindex_timer, on_error_stop => 1);
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -24,7 +24,7 @@ $node->start();
 | 
				
			|||||||
$node->psql('postgres', 'SELECT 1/0');
 | 
					$node->psql('postgres', 'SELECT 1/0');
 | 
				
			||||||
 | 
					
 | 
				
			||||||
# might need to retry if logging collector process is slow...
 | 
					# might need to retry if logging collector process is slow...
 | 
				
			||||||
my $max_attempts = 180 * 10;
 | 
					my $max_attempts = 10 * $TestLib::timeout_default;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $current_logfiles;
 | 
					my $current_logfiles;
 | 
				
			||||||
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
 | 
					for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -271,7 +271,8 @@ my %pgdump_runs = (
 | 
				
			|||||||
			'--no-sync',
 | 
								'--no-sync',
 | 
				
			||||||
			"--file=$tempdir/only_dump_test_table.sql",
 | 
								"--file=$tempdir/only_dump_test_table.sql",
 | 
				
			||||||
			'--table=dump_test.test_table',
 | 
								'--table=dump_test.test_table',
 | 
				
			||||||
			'--lock-wait-timeout=1000000',
 | 
								'--lock-wait-timeout='
 | 
				
			||||||
 | 
								  . (1000 * $TestLib::timeout_default),
 | 
				
			||||||
			'postgres',
 | 
								'postgres',
 | 
				
			||||||
		],
 | 
							],
 | 
				
			||||||
	},
 | 
						},
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -15,6 +15,6 @@ my $node = get_new_node('main');
 | 
				
			|||||||
$node->init;
 | 
					$node->init;
 | 
				
			||||||
$node->start;
 | 
					$node->start;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
# use a long timeout for the benefit of very slow buildfarm machines
 | 
					$node->command_ok(
 | 
				
			||||||
$node->command_ok([qw(pg_isready --timeout=60)],
 | 
						[ 'pg_isready', "--timeout=$TestLib::timeout_default" ],
 | 
				
			||||||
	'succeeds with server running');
 | 
						'succeeds with server running');
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -31,7 +31,8 @@ PostgresNode - class representing PostgreSQL server instance
 | 
				
			|||||||
  my ($stdout, $stderr, $timed_out);
 | 
					  my ($stdout, $stderr, $timed_out);
 | 
				
			||||||
  my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
 | 
					  my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
 | 
				
			||||||
	  stdout => \$stdout, stderr => \$stderr,
 | 
						  stdout => \$stdout, stderr => \$stderr,
 | 
				
			||||||
	  timeout => 180, timed_out => \$timed_out,
 | 
						  timeout => $TestLib::timeout_default,
 | 
				
			||||||
 | 
						  timed_out => \$timed_out,
 | 
				
			||||||
	  extra_params => ['--single-transaction'],
 | 
						  extra_params => ['--single-transaction'],
 | 
				
			||||||
	  on_error_die => 1)
 | 
						  on_error_die => 1)
 | 
				
			||||||
  print "Sleep timed out" if $timed_out;
 | 
					  print "Sleep timed out" if $timed_out;
 | 
				
			||||||
@@ -1412,7 +1413,8 @@ e.g.
 | 
				
			|||||||
	my ($stdout, $stderr, $timed_out);
 | 
						my ($stdout, $stderr, $timed_out);
 | 
				
			||||||
	my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
 | 
						my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
 | 
				
			||||||
		stdout => \$stdout, stderr => \$stderr,
 | 
							stdout => \$stdout, stderr => \$stderr,
 | 
				
			||||||
		timeout => 180, timed_out => \$timed_out,
 | 
							timeout => $TestLib::timeout_default,
 | 
				
			||||||
 | 
							timed_out => \$timed_out,
 | 
				
			||||||
		extra_params => ['--single-transaction'])
 | 
							extra_params => ['--single-transaction'])
 | 
				
			||||||
 | 
					
 | 
				
			||||||
will set $cmdret to undef and $timed_out to a true value.
 | 
					will set $cmdret to undef and $timed_out to a true value.
 | 
				
			||||||
@@ -1569,7 +1571,8 @@ scalar reference.  This allows the caller to act on other parts of the system
 | 
				
			|||||||
while idling this backend.
 | 
					while idling this backend.
 | 
				
			||||||
 | 
					
 | 
				
			||||||
The specified timer object is attached to the harness, as well.  It's caller's
 | 
					The specified timer object is attached to the harness, as well.  It's caller's
 | 
				
			||||||
responsibility to select the timeout length, and to restart the timer after
 | 
					responsibility to set the timeout length (usually
 | 
				
			||||||
 | 
					$TestLib::timeout_default), and to restart the timer after
 | 
				
			||||||
each command if the timeout is per-command.
 | 
					each command if the timeout is per-command.
 | 
				
			||||||
 | 
					
 | 
				
			||||||
psql is invoked in tuples-only unaligned mode with reading of B<.psqlrc>
 | 
					psql is invoked in tuples-only unaligned mode with reading of B<.psqlrc>
 | 
				
			||||||
@@ -1741,7 +1744,7 @@ sub pgbench
 | 
				
			|||||||
Run B<$query> repeatedly, until it returns the B<$expected> result
 | 
					Run B<$query> repeatedly, until it returns the B<$expected> result
 | 
				
			||||||
('t', or SQL boolean true, by default).
 | 
					('t', or SQL boolean true, by default).
 | 
				
			||||||
Continues polling if B<psql> returns an error result.
 | 
					Continues polling if B<psql> returns an error result.
 | 
				
			||||||
Times out after 180 seconds.
 | 
					Times out after $TestLib::timeout_default seconds.
 | 
				
			||||||
Returns 1 if successful, 0 if timed out.
 | 
					Returns 1 if successful, 0 if timed out.
 | 
				
			||||||
 | 
					
 | 
				
			||||||
=cut
 | 
					=cut
 | 
				
			||||||
@@ -1754,7 +1757,7 @@ sub poll_query_until
 | 
				
			|||||||
 | 
					
 | 
				
			||||||
	my $cmd = [ 'psql', '-XAt', '-d', $self->connstr($dbname) ];
 | 
						my $cmd = [ 'psql', '-XAt', '-d', $self->connstr($dbname) ];
 | 
				
			||||||
	my ($stdout, $stderr);
 | 
						my ($stdout, $stderr);
 | 
				
			||||||
	my $max_attempts = 180 * 10;
 | 
						my $max_attempts = 10 * $TestLib::timeout_default;
 | 
				
			||||||
	my $attempts     = 0;
 | 
						my $attempts     = 0;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
	while ($attempts < $max_attempts)
 | 
						while ($attempts < $max_attempts)
 | 
				
			||||||
@@ -1776,8 +1779,8 @@ sub poll_query_until
 | 
				
			|||||||
		$attempts++;
 | 
							$attempts++;
 | 
				
			||||||
	}
 | 
						}
 | 
				
			||||||
 | 
					
 | 
				
			||||||
	# The query result didn't change in 180 seconds. Give up. Print the
 | 
						# Give up. Print the output from the last attempt, hopefully that's useful
 | 
				
			||||||
	# output from the last attempt, hopefully that's useful for debugging.
 | 
						# for debugging.
 | 
				
			||||||
	diag qq(poll_query_until timed out executing this query:
 | 
						diag qq(poll_query_until timed out executing this query:
 | 
				
			||||||
$query
 | 
					$query
 | 
				
			||||||
expecting this output:
 | 
					expecting this output:
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -52,7 +52,7 @@ our @EXPORT = qw(
 | 
				
			|||||||
  $windows_os
 | 
					  $windows_os
 | 
				
			||||||
);
 | 
					);
 | 
				
			||||||
 | 
					
 | 
				
			||||||
our ($windows_os, $tmp_check, $log_path, $test_logfile);
 | 
					our ($windows_os, $timeout_default, $tmp_check, $log_path, $test_logfile);
 | 
				
			||||||
 | 
					
 | 
				
			||||||
BEGIN
 | 
					BEGIN
 | 
				
			||||||
{
 | 
					{
 | 
				
			||||||
@@ -101,6 +101,10 @@ BEGIN
 | 
				
			|||||||
		require Win32API::File;
 | 
							require Win32API::File;
 | 
				
			||||||
		Win32API::File->import(qw(createFile OsFHandleOpen CloseHandle));
 | 
							Win32API::File->import(qw(createFile OsFHandleOpen CloseHandle));
 | 
				
			||||||
	}
 | 
						}
 | 
				
			||||||
 | 
					
 | 
				
			||||||
 | 
						$timeout_default = $ENV{PG_TEST_TIMEOUT_DEFAULT};
 | 
				
			||||||
 | 
						$timeout_default = 180
 | 
				
			||||||
 | 
						  if not defined $timeout_default or $timeout_default eq '';
 | 
				
			||||||
}
 | 
					}
 | 
				
			||||||
 | 
					
 | 
				
			||||||
INIT
 | 
					INIT
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -77,7 +77,7 @@ $node_master->safe_psql('postgres',
 | 
				
			|||||||
);
 | 
					);
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $stdout_recv = $node_master->pg_recvlogical_upto(
 | 
					my $stdout_recv = $node_master->pg_recvlogical_upto(
 | 
				
			||||||
	'postgres', 'test_slot', $endpos, 180,
 | 
						'postgres', 'test_slot', $endpos, $TestLib::timeout_default,
 | 
				
			||||||
	'include-xids'     => '0',
 | 
						'include-xids'     => '0',
 | 
				
			||||||
	'skip-empty-xacts' => '1');
 | 
						'skip-empty-xacts' => '1');
 | 
				
			||||||
chomp($stdout_recv);
 | 
					chomp($stdout_recv);
 | 
				
			||||||
@@ -89,7 +89,7 @@ $node_master->poll_query_until('postgres',
 | 
				
			|||||||
) or die "slot never became inactive";
 | 
					) or die "slot never became inactive";
 | 
				
			||||||
 | 
					
 | 
				
			||||||
$stdout_recv = $node_master->pg_recvlogical_upto(
 | 
					$stdout_recv = $node_master->pg_recvlogical_upto(
 | 
				
			||||||
	'postgres', 'test_slot', $endpos, 180,
 | 
						'postgres', 'test_slot', $endpos, $TestLib::timeout_default,
 | 
				
			||||||
	'include-xids'     => '0',
 | 
						'include-xids'     => '0',
 | 
				
			||||||
	'skip-empty-xacts' => '1');
 | 
						'skip-empty-xacts' => '1');
 | 
				
			||||||
chomp($stdout_recv);
 | 
					chomp($stdout_recv);
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -155,7 +155,7 @@ like(
 | 
				
			|||||||
($ret, $stdout, $stderr) = $node_replica->psql(
 | 
					($ret, $stdout, $stderr) = $node_replica->psql(
 | 
				
			||||||
	'postgres',
 | 
						'postgres',
 | 
				
			||||||
	"SELECT data FROM pg_logical_slot_peek_changes('before_basebackup', NULL, NULL, 'include-xids', '0', 'skip-empty-xacts', '1');",
 | 
						"SELECT data FROM pg_logical_slot_peek_changes('before_basebackup', NULL, NULL, 'include-xids', '0', 'skip-empty-xacts', '1');",
 | 
				
			||||||
	timeout => 180);
 | 
						timeout => $TestLib::timeout_default);
 | 
				
			||||||
is($ret, 0, 'replay from slot before_basebackup succeeds');
 | 
					is($ret, 0, 'replay from slot before_basebackup succeeds');
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $final_expected_output_bb = q(BEGIN
 | 
					my $final_expected_output_bb = q(BEGIN
 | 
				
			||||||
@@ -184,7 +184,7 @@ my $endpos = $node_replica->safe_psql('postgres',
 | 
				
			|||||||
 | 
					
 | 
				
			||||||
$stdout = $node_replica->pg_recvlogical_upto(
 | 
					$stdout = $node_replica->pg_recvlogical_upto(
 | 
				
			||||||
	'postgres', 'before_basebackup',
 | 
						'postgres', 'before_basebackup',
 | 
				
			||||||
	$endpos,    180,
 | 
						$endpos,    $TestLib::timeout_default,
 | 
				
			||||||
	'include-xids'     => '0',
 | 
						'include-xids'     => '0',
 | 
				
			||||||
	'skip-empty-xacts' => '1');
 | 
						'skip-empty-xacts' => '1');
 | 
				
			||||||
 | 
					
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -23,7 +23,7 @@ plan tests => 18;
 | 
				
			|||||||
# instance being driven by us, add a timeout high enough that it
 | 
					# instance being driven by us, add a timeout high enough that it
 | 
				
			||||||
# should never trigger even on very slow machines, unless something
 | 
					# should never trigger even on very slow machines, unless something
 | 
				
			||||||
# is really wrong.
 | 
					# is really wrong.
 | 
				
			||||||
my $psql_timeout = IPC::Run::timer(60);
 | 
					my $psql_timeout = IPC::Run::timer($TestLib::timeout_default);
 | 
				
			||||||
 | 
					
 | 
				
			||||||
my $node = get_new_node('master');
 | 
					my $node = get_new_node('master');
 | 
				
			||||||
$node->init(allows_streaming => 1);
 | 
					$node->init(allows_streaming => 1);
 | 
				
			||||||
 
 | 
				
			|||||||
@@ -122,7 +122,7 @@ my $slow_client = IPC::Run::start(
 | 
				
			|||||||
	\$stdout,
 | 
						\$stdout,
 | 
				
			||||||
	'2>',
 | 
						'2>',
 | 
				
			||||||
	\$stderr,
 | 
						\$stderr,
 | 
				
			||||||
	IPC::Run::timeout(900));    # five times the poll_query_until timeout
 | 
						IPC::Run::timeout(5 * $TestLib::timeout_default));
 | 
				
			||||||
ok( $gnat->poll_query_until(
 | 
					ok( $gnat->poll_query_until(
 | 
				
			||||||
		'postgres',
 | 
							'postgres',
 | 
				
			||||||
		"SELECT 1 FROM pg_stat_activity WHERE query = '$slow_query'", '1'),
 | 
							"SELECT 1 FROM pg_stat_activity WHERE query = '$slow_query'", '1'),
 | 
				
			||||||
@@ -133,10 +133,11 @@ $gnat->kill9;
 | 
				
			|||||||
unlink($gnat->data_dir . '/postmaster.pid');
 | 
					unlink($gnat->data_dir . '/postmaster.pid');
 | 
				
			||||||
$gnat->rotate_logfile;
 | 
					$gnat->rotate_logfile;
 | 
				
			||||||
log_ipcs();
 | 
					log_ipcs();
 | 
				
			||||||
# Reject ordinary startup.  Retry for the same reasons poll_start() does.
 | 
					# Reject ordinary startup.  Retry for the same reasons poll_start() does,
 | 
				
			||||||
 | 
					# every 0.1s for at least $TestLib::timeout_default seconds.
 | 
				
			||||||
my $pre_existing_msg = qr/pre-existing shared memory block/;
 | 
					my $pre_existing_msg = qr/pre-existing shared memory block/;
 | 
				
			||||||
{
 | 
					{
 | 
				
			||||||
	my $max_attempts = 180 * 10;    # Retry every 0.1s for at least 180s.
 | 
						my $max_attempts = 10 * $TestLib::timeout_default;
 | 
				
			||||||
	my $attempts     = 0;
 | 
						my $attempts     = 0;
 | 
				
			||||||
	while ($attempts < $max_attempts)
 | 
						while ($attempts < $max_attempts)
 | 
				
			||||||
	{
 | 
						{
 | 
				
			||||||
@@ -186,7 +187,7 @@ sub poll_start
 | 
				
			|||||||
{
 | 
					{
 | 
				
			||||||
	my ($node) = @_;
 | 
						my ($node) = @_;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
	my $max_attempts = 180 * 10;
 | 
						my $max_attempts = 10 * $TestLib::timeout_default;
 | 
				
			||||||
	my $attempts     = 0;
 | 
						my $attempts     = 0;
 | 
				
			||||||
 | 
					
 | 
				
			||||||
	while ($attempts < $max_attempts)
 | 
						while ($attempts < $max_attempts)
 | 
				
			||||||
@@ -202,8 +203,8 @@ sub poll_start
 | 
				
			|||||||
		$attempts++;
 | 
							$attempts++;
 | 
				
			||||||
	}
 | 
						}
 | 
				
			||||||
 | 
					
 | 
				
			||||||
	# No success within 180 seconds.  Try one last time without fail_ok, which
 | 
						# Try one last time without fail_ok, which will BAIL_OUT unless it
 | 
				
			||||||
	# will BAIL_OUT unless it succeeds.
 | 
						# succeeds.
 | 
				
			||||||
	$node->start && return 1;
 | 
						$node->start && return 1;
 | 
				
			||||||
	return 0;
 | 
						return 0;
 | 
				
			||||||
}
 | 
					}
 | 
				
			||||||
 
 | 
				
			|||||||
		Reference in New Issue
	
	Block a user