pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  
help / color / mirror / Atom feed
Too-short timeouts in test code
4+ messages / 2 participants
[nested] [flat]

* Too-short timeouts in test code
@ 2018-12-09 00:16 Noah Misch <noah@leadboat.com>
  2018-12-09 02:14 ` Re: Too-short timeouts in test code Michael Paquier <michael@paquier.xyz>
  0 siblings, 1 reply; 4+ messages in thread

From: Noah Misch @ 2018-12-09 00:16 UTC (permalink / raw)
  To: pgsql-hackers

We've had more buildfarm failures due to hard-coded, short timeouts:

http://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=chipmunk&dt=2018-10-13%2021%3A06%3A58
  10s timeout while running pg_recvlogical
http://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=hornet&dt=2018-12-03%2005%3A52%3A12
  30s timeout while running pg_recvlogical
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=mandrill&dt=2018-11-30%2014%3A31%3A18
  60s timeout in isolationtester try_complete_step()

The 180s timeout in poll_query_until has been trouble-free since 2a0f89c
introduced it two years ago.  I plan to raise the timeouts in question to
180s, as attached.
diff --git a/src/test/isolation/README b/src/test/isolation/README
index bea278a..780b6dc 100644
--- a/src/test/isolation/README
+++ b/src/test/isolation/README
@@ -108,8 +108,8 @@ Each step may contain commands that block until further action has been taken
 deadlock).  A test that uses this ability must manually specify valid
 permutations, i.e. those that would not expect a blocked session to execute a
 command.  If a test fails to follow that rule, isolationtester will cancel it
-after 60 seconds.  If the cancel doesn't work, isolationtester will exit
-uncleanly after a total of 75 seconds of wait time.  Testing invalid
+after 180 seconds.  If the cancel doesn't work, isolationtester will exit
+uncleanly after a total of 200 seconds of wait time.  Testing invalid
 permutations should be avoided because they can make the isolation tests take
 a very long time to run, and they serve no useful testing purpose.
 
diff --git a/src/test/isolation/isolationtester.c b/src/test/isolation/isolationtester.c
index 7df67da..9134b05 100644
--- a/src/test/isolation/isolationtester.c
+++ b/src/test/isolation/isolationtester.c
@@ -783,15 +783,15 @@ try_complete_step(Step *step, int flags)
 			td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
 
 			/*
-			 * After 60 seconds, try to cancel the query.
+			 * After 180 seconds, try to cancel the query.
 			 *
 			 * If the user tries to test an invalid permutation, we don't want
 			 * to hang forever, especially when this is running in the
-			 * buildfarm.  So try to cancel it after a minute.  This will
-			 * presumably lead to this permutation failing, but remaining
-			 * permutations and tests should still be OK.
+			 * buildfarm.  This will presumably lead to this permutation
+			 * failing, but remaining permutations and tests should still be
+			 * OK.
 			 */
-			if (td > 60 * USECS_PER_SEC && !canceled)
+			if (td > 180 * USECS_PER_SEC && !canceled)
 			{
 				PGcancel   *cancel = PQgetCancel(conn);
 
@@ -808,15 +808,15 @@ try_complete_step(Step *step, int flags)
 			}
 
 			/*
-			 * After 75 seconds, just give up and die.
+			 * After 200 seconds, just give up and die.
 			 *
 			 * Since cleanup steps won't be run in this case, this may cause
 			 * later tests to fail.  That stinks, but it's better than waiting
 			 * forever for the server to respond to the cancel.
 			 */
-			if (td > 75 * USECS_PER_SEC)
+			if (td > 200 * USECS_PER_SEC)
 			{
-				fprintf(stderr, "step %s timed out after 75 seconds\n",
+				fprintf(stderr, "step %s timed out after 200 seconds\n",
 						step->name);
 				exit_nicely();
 			}
diff --git a/src/test/recovery/t/006_logical_decoding.pl b/src/test/recovery/t/006_logical_decoding.pl
index 884b0ae..c23cc4d 100644
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -72,7 +72,7 @@ my $endpos = $node_master->safe_psql('postgres',
 print "waiting to replay $endpos\n";
 
 my $stdout_recv = $node_master->pg_recvlogical_upto(
-	'postgres', 'test_slot', $endpos, 10,
+	'postgres', 'test_slot', $endpos, 180,
 	'include-xids'     => '0',
 	'skip-empty-xacts' => '1');
 chomp($stdout_recv);
@@ -84,7 +84,7 @@ $node_master->poll_query_until('postgres',
 ) or die "slot never became inactive";
 
 $stdout_recv = $node_master->pg_recvlogical_upto(
-	'postgres', 'test_slot', $endpos, 10,
+	'postgres', 'test_slot', $endpos, 180,
 	'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 4fbd386..e582b20 100644
--- a/src/test/recovery/t/010_logical_decoding_timelines.pl
+++ b/src/test/recovery/t/010_logical_decoding_timelines.pl
@@ -183,7 +183,7 @@ my $endpos = $node_replica->safe_psql('postgres',
 
 $stdout = $node_replica->pg_recvlogical_upto(
 	'postgres', 'before_basebackup',
-	$endpos,    30,
+	$endpos,    180,
 	'include-xids'     => '0',
 	'skip-empty-xacts' => '1');
 

Attachments:

  [text/plain] test-timeout-180s-v1.patch (3.9K, ../../20181209001601.GC2973271@rfd.leadboat.com/2-test-timeout-180s-v1.patch)
  download | inline diff:
diff --git a/src/test/isolation/README b/src/test/isolation/README
index bea278a..780b6dc 100644
--- a/src/test/isolation/README
+++ b/src/test/isolation/README
@@ -108,8 +108,8 @@ Each step may contain commands that block until further action has been taken
 deadlock).  A test that uses this ability must manually specify valid
 permutations, i.e. those that would not expect a blocked session to execute a
 command.  If a test fails to follow that rule, isolationtester will cancel it
-after 60 seconds.  If the cancel doesn't work, isolationtester will exit
-uncleanly after a total of 75 seconds of wait time.  Testing invalid
+after 180 seconds.  If the cancel doesn't work, isolationtester will exit
+uncleanly after a total of 200 seconds of wait time.  Testing invalid
 permutations should be avoided because they can make the isolation tests take
 a very long time to run, and they serve no useful testing purpose.
 
diff --git a/src/test/isolation/isolationtester.c b/src/test/isolation/isolationtester.c
index 7df67da..9134b05 100644
--- a/src/test/isolation/isolationtester.c
+++ b/src/test/isolation/isolationtester.c
@@ -783,15 +783,15 @@ try_complete_step(Step *step, int flags)
 			td += (int64) current_time.tv_usec - (int64) start_time.tv_usec;
 
 			/*
-			 * After 60 seconds, try to cancel the query.
+			 * After 180 seconds, try to cancel the query.
 			 *
 			 * If the user tries to test an invalid permutation, we don't want
 			 * to hang forever, especially when this is running in the
-			 * buildfarm.  So try to cancel it after a minute.  This will
-			 * presumably lead to this permutation failing, but remaining
-			 * permutations and tests should still be OK.
+			 * buildfarm.  This will presumably lead to this permutation
+			 * failing, but remaining permutations and tests should still be
+			 * OK.
 			 */
-			if (td > 60 * USECS_PER_SEC && !canceled)
+			if (td > 180 * USECS_PER_SEC && !canceled)
 			{
 				PGcancel   *cancel = PQgetCancel(conn);
 
@@ -808,15 +808,15 @@ try_complete_step(Step *step, int flags)
 			}
 
 			/*
-			 * After 75 seconds, just give up and die.
+			 * After 200 seconds, just give up and die.
 			 *
 			 * Since cleanup steps won't be run in this case, this may cause
 			 * later tests to fail.  That stinks, but it's better than waiting
 			 * forever for the server to respond to the cancel.
 			 */
-			if (td > 75 * USECS_PER_SEC)
+			if (td > 200 * USECS_PER_SEC)
 			{
-				fprintf(stderr, "step %s timed out after 75 seconds\n",
+				fprintf(stderr, "step %s timed out after 200 seconds\n",
 						step->name);
 				exit_nicely();
 			}
diff --git a/src/test/recovery/t/006_logical_decoding.pl b/src/test/recovery/t/006_logical_decoding.pl
index 884b0ae..c23cc4d 100644
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -72,7 +72,7 @@ my $endpos = $node_master->safe_psql('postgres',
 print "waiting to replay $endpos\n";
 
 my $stdout_recv = $node_master->pg_recvlogical_upto(
-	'postgres', 'test_slot', $endpos, 10,
+	'postgres', 'test_slot', $endpos, 180,
 	'include-xids'     => '0',
 	'skip-empty-xacts' => '1');
 chomp($stdout_recv);
@@ -84,7 +84,7 @@ $node_master->poll_query_until('postgres',
 ) or die "slot never became inactive";
 
 $stdout_recv = $node_master->pg_recvlogical_upto(
-	'postgres', 'test_slot', $endpos, 10,
+	'postgres', 'test_slot', $endpos, 180,
 	'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 4fbd386..e582b20 100644
--- a/src/test/recovery/t/010_logical_decoding_timelines.pl
+++ b/src/test/recovery/t/010_logical_decoding_timelines.pl
@@ -183,7 +183,7 @@ my $endpos = $node_replica->safe_psql('postgres',
 
 $stdout = $node_replica->pg_recvlogical_upto(
 	'postgres', 'before_basebackup',
-	$endpos,    30,
+	$endpos,    180,
 	'include-xids'     => '0',
 	'skip-empty-xacts' => '1');
 

^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: Too-short timeouts in test code
  2018-12-09 00:16 Too-short timeouts in test code Noah Misch <noah@leadboat.com>
@ 2018-12-09 02:14 ` Michael Paquier <michael@paquier.xyz>
  2018-12-09 02:24   ` Re: Too-short timeouts in test code Noah Misch <noah@leadboat.com>
  0 siblings, 1 reply; 4+ messages in thread

From: Michael Paquier @ 2018-12-09 02:14 UTC (permalink / raw)
  To: Noah Misch <noah@leadboat.com>; +Cc: pgsql-hackers

On Sat, Dec 08, 2018 at 04:16:01PM -0800, Noah Misch wrote:
> The 180s timeout in poll_query_until has been trouble-free since 2a0f89c
> introduced it two years ago.  I plan to raise the timeouts in question to
> 180s, as attached.

That's annoying, thanks for tracking those down.

> @@ -72,7 +72,7 @@ my $endpos = $node_master->safe_psql('postgres',
>  print "waiting to replay $endpos\n";
>  
>  my $stdout_recv = $node_master->pg_recvlogical_upto(
> -	'postgres', 'test_slot', $endpos, 10,
> +	'postgres', 'test_slot', $endpos, 180,
>  	'include-xids'     => '0',
>  	'skip-empty-xacts' => '1');

Instead of allowing callers of pg_recvlogical_upto() to define the
timeout they want, perhaps it would be better to hardcode the timeout
limit within the routine?
--
Michael

Attachments:

  [application/pgp-signature] signature.asc (832B, ../../20181209021412.GC1833@paquier.xyz/2-signature.asc)
  download

^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: Too-short timeouts in test code
  2018-12-09 00:16 Too-short timeouts in test code Noah Misch <noah@leadboat.com>
  2018-12-09 02:14 ` Re: Too-short timeouts in test code Michael Paquier <michael@paquier.xyz>
@ 2018-12-09 02:24   ` Noah Misch <noah@leadboat.com>
  2018-12-09 03:26     ` Re: Too-short timeouts in test code Michael Paquier <michael@paquier.xyz>
  0 siblings, 1 reply; 4+ messages in thread

From: Noah Misch @ 2018-12-09 02:24 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; +Cc: pgsql-hackers

On Sun, Dec 09, 2018 at 11:14:12AM +0900, Michael Paquier wrote:
> On Sat, Dec 08, 2018 at 04:16:01PM -0800, Noah Misch wrote:
> > @@ -72,7 +72,7 @@ my $endpos = $node_master->safe_psql('postgres',
> >  print "waiting to replay $endpos\n";
> >  
> >  my $stdout_recv = $node_master->pg_recvlogical_upto(
> > -	'postgres', 'test_slot', $endpos, 10,
> > +	'postgres', 'test_slot', $endpos, 180,
> >  	'include-xids'     => '0',
> >  	'skip-empty-xacts' => '1');
> 
> Instead of allowing callers of pg_recvlogical_upto() to define the
> timeout they want, perhaps it would be better to hardcode the timeout
> limit within the routine?

pg_recvlogical_upto() has the ability to make timeout non-fatal, by calling it
in an array context.  No in-tree test uses that.  Out-of-tree code using that
feature would likely benefit from the ability to set timeout duration.  Hence,
I'm inclined not remove the timeout duration parameter.




^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: Too-short timeouts in test code
  2018-12-09 00:16 Too-short timeouts in test code Noah Misch <noah@leadboat.com>
  2018-12-09 02:14 ` Re: Too-short timeouts in test code Michael Paquier <michael@paquier.xyz>
  2018-12-09 02:24   ` Re: Too-short timeouts in test code Noah Misch <noah@leadboat.com>
@ 2018-12-09 03:26     ` Michael Paquier <michael@paquier.xyz>
  0 siblings, 0 replies; 4+ messages in thread

From: Michael Paquier @ 2018-12-09 03:26 UTC (permalink / raw)
  To: Noah Misch <noah@leadboat.com>; +Cc: pgsql-hackers

On Sat, Dec 08, 2018 at 06:24:35PM -0800, Noah Misch wrote:
> pg_recvlogical_upto() has the ability to make timeout non-fatal, by calling it
> in an array context.  No in-tree test uses that.  Out-of-tree code using that
> feature would likely benefit from the ability to set timeout duration.  Hence,
> I'm inclined not remove the timeout duration parameter.

No objections with this line of thoughts.  The rest of the patch looks
fine to me.
--
Michael

Attachments:

  [application/pgp-signature] signature.asc (832B, ../../20181209032654.GE1833@paquier.xyz/2-signature.asc)
  download

^ permalink  raw  reply  [nested|flat] 4+ messages in thread


end of thread, other threads:[~2018-12-09 03:26 UTC | newest]

Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2018-12-09 00:16 Too-short timeouts in test code Noah Misch <noah@leadboat.com>
2018-12-09 02:14 ` Michael Paquier <michael@paquier.xyz>
2018-12-09 02:24   ` Noah Misch <noah@leadboat.com>
2018-12-09 03:26     ` Michael Paquier <michael@paquier.xyz>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox