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[email protected]

diff --git a/src/bin/pg_dump/t/002_pg_dump.pl b/src/bin/pg_dump/t/002_pg_dump.pl
index f59fcb6491a69e050b5677e7e7cb2d5aaddb55a2..8819999461a5f11026354b454d55e49ef977b17b 100644 (file)
--- a/src/bin/pg_dump/t/002_pg_dump.pl
+++ b/src/bin/pg_dump/t/002_pg_dump.pl
@@ -209,7 +209,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', ], },
    role => {
        dump_cmd => [

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 d01804da37165a785b99701ad940d9dc91cc1890..fc2f54f061c106076d7312c4cac514764cf0824e 100644 (file)
--- a/src/bin/scripts/t/080_pg_isready.pl
+++ b/src/bin/scripts/t/080_pg_isready.pl
@@ -15,5 +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)], 'succeeds with server running');
+$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 099d4981e5e21c7d4304f34ca2d11257c1e0b0e6..d673494e8897e5fe67256d2f4b53aa6294111aa7 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;
@@ -1246,7 +1247,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.
@@ -1403,7 +1405,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>
@@ -1624,7 +1627,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
@@ -1637,7 +1640,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)
@@ -1659,8 +1662,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 6a738ba8b953e05bd882f67ec1b64e8378b92474..73db8f43406d0760ae844f39a35676c903de49c9 100644 (file)
--- a/src/test/perl/TestLib.pm
+++ b/src/test/perl/TestLib.pm
@@ -45,7 +45,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
 {
@@ -92,6 +92,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 5b6731f7df00b965256c5db489e600a01e130a63..7e297c6c2c0db0f612c7c3c4ccf222c2dbbaba23 100644 (file)
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -76,7 +76,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 b9d2638815ad44344c6202dd1461828ed15822e5..ee5b31d975b577ec057d2408a8d8142daefb0dfb 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/017_shm.pl b/src/test/recovery/t/017_shm.pl
index 94bc43ed07318c7e855c84eadedcd9108837fced..a2e2c2659ee337136670962185fcc5629d8f7628 100644 (file)
--- a/src/test/recovery/t/017_shm.pl
+++ b/src/test/recovery/t/017_shm.pl
@@ -120,7 +120,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'),
@@ -131,10 +131,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)
    {
@@ -184,7 +185,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)
@@ -200,8 +201,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;
 }