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

diff --git a/src/bin/pg_dump/t/002_pg_dump.pl b/src/bin/pg_dump/t/002_pg_dump.pl
index f834afaf56983ba7ed86190d7c8236b604521dc4..5c8b96ece2b8f89ed4c503b99907b32ff8fccdd2 100644 (file)
--- a/src/bin/pg_dump/t/002_pg_dump.pl
+++ b/src/bin/pg_dump/t/002_pg_dump.pl
@@ -258,7 +258,8 @@ my %pgdump_runs = (
            '--no-sync',
            "--file=$tempdir/only_dump_test_table.sql",
            '--table=dump_test.test_table',
-           '--lock-wait-timeout=1000000',
+           '--lock-wait-timeout='
+             . (1000 * $TestLib::timeout_default),
            'postgres',
        ],
    },

diff --git a/src/bin/pgbench/t/022_cic.pl b/src/bin/pgbench/t/022_cic.pl
index a1cda5b47ae584f7e7172dd3a66d2ed1e68973c7..2a874bdf26ec027c497f8a995349abf7d52c385d 100644 (file)
--- a/src/bin/pgbench/t/022_cic.pl
+++ b/src/bin/pgbench/t/022_cic.pl
@@ -18,7 +18,8 @@ my ($node, $result);
 #
 $node = get_new_node('CIC_test');
 $node->init;
-$node->append_conf('postgresql.conf', 'lock_timeout = 180000');
+$node->append_conf('postgresql.conf',
+   'lock_timeout = ' . (1000 * $TestLib::timeout_default));
 $node->start;
 $node->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 $node->safe_psql('postgres', q(CREATE INDEX idx ON tbl(i)));
@@ -48,7 +49,7 @@ $node->safe_psql(
 # Run background pgbench with CIC. We cannot mix-in this script into single
 # pgbench: CIC will deadlock with itself occasionally.
 my $pgbench_out   = '';
-my $pgbench_timer = IPC::Run::timeout(180);
+my $pgbench_timer = IPC::Run::timeout($TestLib::timeout_default);
 my $pgbench_h     = $node->background_pgbench(
    '--no-vacuum --client=1 --transactions=200',
    {

diff --git a/src/bin/pgbench/t/023_cic_2pc.pl b/src/bin/pgbench/t/023_cic_2pc.pl
index 5d695819a34a120035dde3078684d7c955b8d19a..b1355a246019bbbeafa96ae5b1e5e6e3dbeb49cd 100644 (file)
--- a/src/bin/pgbench/t/023_cic_2pc.pl
+++ b/src/bin/pgbench/t/023_cic_2pc.pl
@@ -22,7 +22,8 @@ my ($node, $result);
 $node = get_new_node('CIC_2PC_test');
 $node->init;
 $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->safe_psql('postgres', q(CREATE TABLE tbl(i int)));
 $node->safe_psql(
@@ -55,7 +56,7 @@ $node->safe_psql(
 
 my $main_in    = '';
 my $main_out   = '';
-my $main_timer = IPC::Run::timeout(180);
+my $main_timer = IPC::Run::timeout($TestLib::timeout_default);
 
 my $main_h =
   $node->background_psql('postgres', \$main_in, \$main_out,
@@ -69,7 +70,7 @@ pump $main_h until $main_out =~ /syncpoint1/ || $main_timer->is_expired;
 
 my $cic_in    = '';
 my $cic_out   = '';
-my $cic_timer = IPC::Run::timeout(180);
+my $cic_timer = IPC::Run::timeout($TestLib::timeout_default);
 my $cic_h =
   $node->background_psql('postgres', \$cic_in, \$cic_out,
    $cic_timer, on_error_stop => 1);
@@ -131,9 +132,10 @@ PREPARE TRANSACTION 'persists_forever';
 ));
 $node->restart;
 
-my $reindex_in    = '';
-my $reindex_out   = '';
-my $reindex_timer = IPC::Run::timeout(180);
+my $reindex_in  = '';
+my $reindex_out = '';
+my $reindex_timer =
+  IPC::Run::timeout($TestLib::timeout_default);
 my $reindex_h =
   $node->background_psql('postgres', \$reindex_in, \$reindex_out,
    $reindex_timer, on_error_stop => 1);
@@ -161,7 +163,7 @@ $node->safe_psql('postgres', q(REINDEX TABLE tbl;));
 # Run background pgbench with CIC. We cannot mix-in this script into single
 # pgbench: CIC will deadlock with itself occasionally.
 my $pgbench_out   = '';
-my $pgbench_timer = IPC::Run::timeout(180);
+my $pgbench_timer = IPC::Run::timeout($TestLib::timeout_default);
 my $pgbench_h     = $node->background_pgbench(
    '--no-vacuum --client=1 --transactions=100',
    {

diff --git a/src/bin/scripts/t/080_pg_isready.pl b/src/bin/scripts/t/080_pg_isready.pl
index 6da89e1b04f314a4c636528fd242320f553e032e..fc2f54f061c106076d7312c4cac514764cf0824e 100644 (file)
--- a/src/bin/scripts/t/080_pg_isready.pl
+++ b/src/bin/scripts/t/080_pg_isready.pl
@@ -15,6 +15,6 @@ my $node = get_new_node('main');
 $node->init;
 $node->start;
 
-# use a long timeout for the benefit of very slow buildfarm machines
-$node->command_ok([qw(pg_isready --timeout=60)],
+$node->command_ok(
+   [ 'pg_isready', "--timeout=$TestLib::timeout_default" ],
    'succeeds with server running');

diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm
index 556052f6c6bf55cecb09a8878f829e248d213748..2816284aa021c6a5c1c96a022bd0d61f83e0d002 100644 (file)
--- a/src/test/perl/PostgresNode.pm
+++ b/src/test/perl/PostgresNode.pm
@@ -31,7 +31,8 @@ PostgresNode - class representing PostgreSQL server instance
   my ($stdout, $stderr, $timed_out);
   my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
      stdout => \$stdout, stderr => \$stderr,
-     timeout => 180, timed_out => \$timed_out,
+     timeout => $TestLib::timeout_default,
+     timed_out => \$timed_out,
      extra_params => ['--single-transaction'],
      on_error_die => 1)
   print "Sleep timed out" if $timed_out;
@@ -1363,7 +1364,8 @@ e.g.
    my ($stdout, $stderr, $timed_out);
    my $cmdret = $node->psql('postgres', 'SELECT pg_sleep(600)',
        stdout => \$stdout, stderr => \$stderr,
-       timeout => 180, timed_out => \$timed_out,
+       timeout => $TestLib::timeout_default,
+       timed_out => \$timed_out,
        extra_params => ['--single-transaction'])
 
 will set $cmdret to undef and $timed_out to a true value.
@@ -1520,7 +1522,8 @@ scalar reference.  This allows the caller to act on other parts of the system
 while idling this backend.
 
 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.
 
 psql is invoked in tuples-only unaligned mode with reading of B<.psqlrc>
@@ -1741,7 +1744,7 @@ sub background_pgbench
 Run B<$query> repeatedly, until it returns the B<$expected> result
 ('t', or SQL boolean true, by default).
 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.
 
 =cut
@@ -1754,7 +1757,7 @@ sub poll_query_until
 
    my $cmd = [ 'psql', '-XAt', '-d', $self->connstr($dbname) ];
    my ($stdout, $stderr);
-   my $max_attempts = 180 * 10;
+   my $max_attempts = 10 * $TestLib::timeout_default;
    my $attempts     = 0;
 
    while ($attempts < $max_attempts)
@@ -1776,8 +1779,8 @@ sub poll_query_until
        $attempts++;
    }
 
-   # The query result didn't change in 180 seconds. Give up. Print the
-   # output from the last attempt, hopefully that's useful for debugging.
+   # Give up. Print the output from the last attempt, hopefully that's useful
+   # for debugging.
    diag qq(poll_query_until timed out executing this query:
 $query
 expecting this output:

diff --git a/src/test/perl/TestLib.pm b/src/test/perl/TestLib.pm
index 74b7e6e06e9439fd4fb33087450d956349a080e4..c48e524dd1550b62a9e66fc42a555d513754580e 100644 (file)
--- a/src/test/perl/TestLib.pm
+++ b/src/test/perl/TestLib.pm
@@ -51,7 +51,7 @@ our @EXPORT = qw(
   $windows_os
 );
 
-our ($windows_os, $tmp_check, $log_path, $test_logfile);
+our ($windows_os, $timeout_default, $tmp_check, $log_path, $test_logfile);
 
 BEGIN
 {
@@ -98,6 +98,10 @@ BEGIN
        require Win32API::File;
        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

diff --git a/src/test/recovery/t/006_logical_decoding.pl b/src/test/recovery/t/006_logical_decoding.pl
index 1334bf6a6018db5355ef3ed6fedf8e83779d9cab..2237a9bcdcb3a10add35fde8518dbabf60c641c7 100644 (file)
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -77,7 +77,7 @@ $node_master->safe_psql('postgres',
 );
 
 my $stdout_recv = $node_master->pg_recvlogical_upto(
-   'postgres', 'test_slot', $endpos, 180,
+   'postgres', 'test_slot', $endpos, $TestLib::timeout_default,
    'include-xids'     => '0',
    'skip-empty-xacts' => '1');
 chomp($stdout_recv);
@@ -89,7 +89,7 @@ $node_master->poll_query_until('postgres',
 ) or die "slot never became inactive";
 
 $stdout_recv = $node_master->pg_recvlogical_upto(
-   'postgres', 'test_slot', $endpos, 180,
+   'postgres', 'test_slot', $endpos, $TestLib::timeout_default,
    'include-xids'     => '0',
    'skip-empty-xacts' => '1');
 chomp($stdout_recv);

diff --git a/src/test/recovery/t/010_logical_decoding_timelines.pl b/src/test/recovery/t/010_logical_decoding_timelines.pl
index f124ef2179ad6bcdd4bc6fe95dac958c0b871d58..c4d99c7b861dfaf4dc47ac1e361fc8c0d7d6d9cd 100644 (file)
--- a/src/test/recovery/t/010_logical_decoding_timelines.pl
+++ b/src/test/recovery/t/010_logical_decoding_timelines.pl
@@ -155,7 +155,7 @@ like(
 ($ret, $stdout, $stderr) = $node_replica->psql(
    'postgres',
    "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');
 
 my $final_expected_output_bb = q(BEGIN
@@ -184,7 +184,7 @@ my $endpos = $node_replica->safe_psql('postgres',
 
 $stdout = $node_replica->pg_recvlogical_upto(
    'postgres', 'before_basebackup',
-   $endpos,    180,
+   $endpos,    $TestLib::timeout_default,
    'include-xids'     => '0',
    'skip-empty-xacts' => '1');
 

diff --git a/src/test/recovery/t/013_crash_restart.pl b/src/test/recovery/t/013_crash_restart.pl
index 44ae421647b3abd56c7a33537446f37ea733ec5b..db698a43efee6d12e9b270960e92d682c1087245 100644 (file)
--- a/src/test/recovery/t/013_crash_restart.pl
+++ b/src/test/recovery/t/013_crash_restart.pl
@@ -23,7 +23,7 @@ plan tests => 18;
 # instance being driven by us, add a timeout high enough that it
 # should never trigger even on very slow machines, unless something
 # 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');
 $node->init(allows_streaming => 1);

diff --git a/src/test/recovery/t/017_shm.pl b/src/test/recovery/t/017_shm.pl
index 52f3dd993c9db1ee877c3e6ce63fc397ddd8e9ac..0ae57c61b01f0c779a54f7b3d1e196dcd82fbdae 100644 (file)
--- a/src/test/recovery/t/017_shm.pl
+++ b/src/test/recovery/t/017_shm.pl
@@ -122,7 +122,7 @@ my $slow_client = IPC::Run::start(
    \$stdout,
    '2>',
    \$stderr,
-   IPC::Run::timeout(900));    # five times the poll_query_until timeout
+   IPC::Run::timeout(5 * $TestLib::timeout_default));
 ok( $gnat->poll_query_until(
        'postgres',
        "SELECT 1 FROM pg_stat_activity WHERE query = '$slow_query'", '1'),
@@ -133,10 +133,11 @@ $gnat->kill9;
 unlink($gnat->data_dir . '/postmaster.pid');
 $gnat->rotate_logfile;
 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 $max_attempts = 180 * 10;    # Retry every 0.1s for at least 180s.
+   my $max_attempts = 10 * $TestLib::timeout_default;
    my $attempts     = 0;
    while ($attempts < $max_attempts)
    {
@@ -186,7 +187,7 @@ sub poll_start
 {
    my ($node) = @_;
 
-   my $max_attempts = 180 * 10;
+   my $max_attempts = 10 * $TestLib::timeout_default;
    my $attempts     = 0;
 
    while ($attempts < $max_attempts)
@@ -202,8 +203,8 @@ sub poll_start
        $attempts++;
    }
 
-   # No success within 180 seconds.  Try one last time without fail_ok, which
-   # will BAIL_OUT unless it succeeds.
+   # Try one last time without fail_ok, which will BAIL_OUT unless it
+   # succeeds.
    $node->start && return 1;
    return 0;
 }