Skip to content

Commit f60bb3e

Browse files
nmischnmisch
committed
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
1 parent a008c03 commit f60bb3e

18 files changed

+63
-55
lines changed

‎contrib/amcheck/t/002_cic.pl

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,8 @@
1818
#
1919
$node = get_new_node('CIC_test');
2020
$node->init;
21-
$node->append_conf('postgresql.conf', 'lock_timeout = 180000');
21+
$node->append_conf('postgresql.conf',
22+
'lock_timeout = ' . (1000 * $TestLib::timeout_default));
2223
$node->start;
2324
$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
2425
$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));

‎contrib/amcheck/t/003_cic_2pc.pl

Lines changed: 8 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,8 @@
2222
$node = get_new_node('CIC_2PC_test');
2323
$node->init;
2424
$node->append_conf('postgresql.conf', 'max_prepared_transactions = 10');
25-
$node->append_conf('postgresql.conf', 'lock_timeout = 180000');
25+
$node->append_conf('postgresql.conf',
26+
'lock_timeout = ' . (1000 * $TestLib::timeout_default));
2627
$node->start;
2728
$node->safe_psql('postgres', q(CREATE EXTENSION amcheck));
2829
$node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
@@ -38,7 +39,7 @@
3839

3940
my $main_in = '';
4041
my $main_out = '';
41-
my $main_timer = IPC::Run::timeout(180);
42+
my $main_timer = IPC::Run::timeout($TestLib::timeout_default);
4243

4344
my $main_h =
4445
$node->background_psql('postgres', \$main_in, \$main_out,
@@ -52,7 +53,7 @@
5253

5354
my $cic_in = '';
5455
my $cic_out = '';
55-
my $cic_timer = IPC::Run::timeout(180);
56+
my $cic_timer = IPC::Run::timeout($TestLib::timeout_default);
5657
my $cic_h =
5758
$node->background_psql('postgres', \$cic_in, \$cic_out,
5859
$cic_timer, on_error_stop => 1);
@@ -113,9 +114,10 @@
113114
));
114115
$node->restart;
115116

116-
my $reindex_in = '';
117-
my $reindex_out = '';
118-
my $reindex_timer = IPC::Run::timeout(180);
117+
my $reindex_in = '';
118+
my $reindex_out = '';
119+
my $reindex_timer =
120+
IPC::Run::timeout($TestLib::timeout_default);
119121
my $reindex_h =
120122
$node->background_psql('postgres', \$reindex_in, \$reindex_out,
121123
$reindex_timer, on_error_stop => 1);

‎src/bin/pg_ctl/t/004_logrotate.pl

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@
2727
$node->psql('postgres', 'SELECT 1/0');
2828

2929
# might need to retry if logging collector process is slow...
30-
my $max_attempts = 180 * 10;
30+
my $max_attempts = 10 * $TestLib::timeout_default;
3131

3232
my $current_logfiles;
3333
for (my $attempts = 0; $attempts < $max_attempts; $attempts++)

‎src/bin/pg_dump/t/002_pg_dump.pl

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -281,7 +281,8 @@
281281
'--no-sync',
282282
"--file=$tempdir/only_dump_test_table.sql",
283283
'--table=dump_test.test_table',
284-
'--lock-wait-timeout=1000000',
284+
'--lock-wait-timeout='
285+
. (1000 * $TestLib::timeout_default),
285286
'postgres',
286287
],
287288
},

‎src/bin/psql/t/010_tab_completion.pl

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,7 @@
9292
my $in = '';
9393
my $out = '';
9494

95-
my $timer = timer(5);
95+
my $timer = timer($TestLib::timeout_default);
9696

9797
my $h = $node->interactive_psql('postgres', \$in, \$out, $timer);
9898

@@ -109,7 +109,7 @@ sub check_completion
109109
# reset output collector
110110
$out = "";
111111
# restart per-command timer
112-
$timer->start(5);
112+
$timer->start($TestLib::timeout_default);
113113
# send the data to be sent
114114
$in .= $send;
115115
# wait ...
@@ -235,7 +235,7 @@ sub clear_line
235235
clear_line();
236236

237237
# send psql an explicit \q to shut it down, else pty won't close properly
238-
$timer->start(5);
238+
$timer->start($TestLib::timeout_default);
239239
$in .= "\\q\n";
240240
finish $h or die "psql returned $?";
241241
$timer->reset;

‎src/bin/scripts/t/080_pg_isready.pl

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,6 @@
1818
$node->init;
1919
$node->start;
2020

21-
# use a long timeout for the benefit of very slow buildfarm machines
22-
$node->command_ok([qw(pg_isready --timeout=60)],
21+
$node->command_ok(
22+
[ 'pg_isready', "--timeout=$TestLib::timeout_default" ],
2323
'succeeds with server running');

‎src/test/perl/PostgresNode.pm

Lines changed: 14 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,8 @@ PostgresNode - class representing PostgreSQL server instance
3333
my ($stdout, $stderr, $timed_out);
3434
my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
3535
stdout => \$stdout, stderr => \$stderr,
36-
timeout => 180, timed_out => \$timed_out,
36+
timeout => $TestLib::timeout_default,
37+
timed_out => \$timed_out,
3738
extra_params => ['--single-transaction'],
3839
on_error_die => 1)
3940
print "Sleep timed out" if $timed_out;
@@ -1650,7 +1651,8 @@ e.g.
16501651
my ($stdout, $stderr, $timed_out);
16511652
my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
16521653
stdout => \$stdout, stderr => \$stderr,
1653-
timeout => 180, timed_out => \$timed_out,
1654+
timeout => $TestLib::timeout_default,
1655+
timed_out => \$timed_out,
16541656
extra_params => ['--single-transaction'])
16551657
16561658
will set $cmdret to undef and $timed_out to a true value.
@@ -1824,7 +1826,8 @@ scalar reference. This allows the caller to act on other parts of the system
18241826
while idling this backend.
18251827
18261828
The specified timer object is attached to the harness, as well. It's caller's
1827-
responsibility to select the timeout length, and to restart the timer after
1829+
responsibility to set the timeout length (usually
1830+
$TestLib::timeout_default), and to restart the timer after
18281831
each command if the timeout is per-command.
18291832
18301833
psql is invoked in tuples-only unaligned mode with reading of B<.psqlrc>
@@ -1912,9 +1915,10 @@ The process's stdin is sourced from the $stdin scalar reference,
19121915
and its stdout and stderr go to the $stdout scalar reference.
19131916
ptys are used so that psql thinks it's being called interactively.
19141917
1915-
The specified timer object is attached to the harness, as well.
1916-
It's caller's responsibility to select the timeout length, and to
1917-
restart the timer after each command if the timeout is per-command.
1918+
The specified timer object is attached to the harness, as well. It's caller's
1919+
responsibility to set the timeout length (usually
1920+
$TestLib::timeout_default), and to restart the timer after
1921+
each command if the timeout is per-command.
19181922
19191923
psql is invoked in tuples-only unaligned mode with reading of B<.psqlrc>
19201924
disabled. That may be overridden by passing extra psql parameters.
@@ -2227,7 +2231,7 @@ sub connect_fails
22272231
Run B<$query> repeatedly, until it returns the B<$expected> result
22282232
('t', or SQL boolean true, by default).
22292233
Continues polling if B<psql> returns an error result.
2230-
Times out after 180 seconds.
2234+
Times out after $TestLib::timeout_default seconds.
22312235
Returns 1 if successful, 0 if timed out.
22322236
22332237
=cut
@@ -2245,7 +2249,7 @@ sub poll_query_until
22452249
'-d', $self->connstr($dbname)
22462250
];
22472251
my ($stdout, $stderr);
2248-
my $max_attempts = 180 * 10;
2252+
my $max_attempts = 10 * $TestLib::timeout_default;
22492253
my $attempts = 0;
22502254

22512255
while ($attempts < $max_attempts)
@@ -2267,8 +2271,8 @@ sub poll_query_until
22672271
$attempts++;
22682272
}
22692273

2270-
# The query result didn't change in 180 seconds. Give up. Print the
2271-
# output from the last attempt, hopefully that's useful for debugging.
2274+
# Give up. Print the output from the last attempt, hopefully that's useful
2275+
# for debugging.
22722276
diag qq(poll_query_until timed out executing this query:
22732277
$query
22742278
expecting this output:

‎src/test/perl/TestLib.pm

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -91,8 +91,8 @@ our @EXPORT = qw(
9191
$use_unix_sockets
9292
);
9393

94-
our ($windows_os, $is_msys2, $use_unix_sockets, $tmp_check, $log_path,
95-
$test_logfile);
94+
our ($windows_os, $is_msys2, $use_unix_sockets, $timeout_default,
95+
$tmp_check, $log_path, $test_logfile);
9696

9797
BEGIN
9898
{
@@ -157,6 +157,10 @@ BEGIN
157157
# supported, but it can be overridden if desired.
158158
$use_unix_sockets =
159159
(!$windows_os || defined $ENV{PG_TEST_USE_UNIX_SOCKETS});
160+
161+
$timeout_default = $ENV{PG_TEST_TIMEOUT_DEFAULT};
162+
$timeout_default = 180
163+
if not defined $timeout_default or $timeout_default eq '';
160164
}
161165

162166
=pod

‎src/test/recovery/t/003_recovery_targets.pl

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -172,8 +172,8 @@ sub test_recovery_standby
172172
$node_standby->logfile, 'start'
173173
]);
174174

175-
# wait up to 180s for postgres to terminate
176-
foreach my $i (0 .. 1800)
175+
# wait for postgres to terminate
176+
foreach my $i (0 .. 10 * $TestLib::timeout_default)
177177
{
178178
last if !-f $node_standby->data_dir . '/postmaster.pid';
179179
usleep(100_000);

‎src/test/recovery/t/006_logical_decoding.pl

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -98,7 +98,8 @@
9898
);
9999

100100
my $stdout_recv = $node_primary->pg_recvlogical_upto(
101-
'postgres', 'test_slot', $endpos, 180,
101+
'postgres', 'test_slot', $endpos,
102+
$TestLib::timeout_default,
102103
'include-xids' => '0',
103104
'skip-empty-xacts' => '1');
104105
chomp($stdout_recv);
@@ -110,7 +111,8 @@
110111
) or die "slot never became inactive";
111112

112113
$stdout_recv = $node_primary->pg_recvlogical_upto(
113-
'postgres', 'test_slot', $endpos, 180,
114+
'postgres', 'test_slot', $endpos,
115+
$TestLib::timeout_default,
114116
'include-xids' => '0',
115117
'skip-empty-xacts' => '1');
116118
chomp($stdout_recv);

0 commit comments

Comments
 (0)