Re: Race conditions with TAP test for syncrep

2019-07-23 Thread Michael Paquier
On Tue, Jul 23, 2019 at 05:04:32PM +0900, Michael Paquier wrote:
> Thanks Noah for the review.  I have reviewed the thread and improved a
> couple of comments based on Alvaro's previous input.  Attached is v2.
> If there are no objections, I would be fine to commit it.

Applied and back-patched down to 9.6 where it applies.  Thanks for the
reviews.
--
Michael


signature.asc
Description: PGP signature


Re: Race conditions with TAP test for syncrep

2019-07-23 Thread Michael Paquier
On Mon, Jul 22, 2019 at 11:45:53PM -0700, Noah Misch wrote:
> PostgresNode uses "print" the same way.  The patch does close the intended
> race conditions, and its implementation choices look fine to me.

Thanks Noah for the review.  I have reviewed the thread and improved a
couple of comments based on Alvaro's previous input.  Attached is v2.
If there are no objections, I would be fine to commit it.
--
Michael
diff --git a/src/test/recovery/t/007_sync_rep.pl b/src/test/recovery/t/007_sync_rep.pl
index bba47da17a..8ce77ffbcf 100644
--- a/src/test/recovery/t/007_sync_rep.pl
+++ b/src/test/recovery/t/007_sync_rep.pl
@@ -27,6 +27,23 @@ sub test_sync_state
 	return;
 }
 
+# Start a standby and check that it is registered within the WAL sender
+# array of the given primary.  This polls the primary's pg_stat_replication
+# until the standby is confirmed as registered.
+sub start_standby_and_wait
+{
+	my ($master, $standby) = @_;
+	my $master_name  = $master->name;
+	my $standby_name = $standby->name;
+	my $query =
+	  "SELECT count(1) = 1 FROM pg_stat_replication WHERE application_name = '$standby_name'";
+
+	$standby->start;
+
+	print "### Waiting for standby \"$standby_name\" on \"$master_name\"\n";
+	$master->poll_query_until('postgres', $query);
+}
+
 # Initialize master node
 my $node_master = get_new_node('master');
 $node_master->init(allows_streaming => 1);
@@ -36,23 +53,27 @@ my $backup_name = 'master_backup';
 # Take backup
 $node_master->backup($backup_name);
 
+# Create all the standbys.  Their status on the primary is checked to
+# ensure the ordering of each one of them in the WAL sender array of the
+# primary.
+
 # Create standby1 linking to master
 my $node_standby_1 = get_new_node('standby1');
 $node_standby_1->init_from_backup($node_master, $backup_name,
 	has_streaming => 1);
-$node_standby_1->start;
+start_standby_and_wait($node_master, $node_standby_1);
 
 # Create standby2 linking to master
 my $node_standby_2 = get_new_node('standby2');
 $node_standby_2->init_from_backup($node_master, $backup_name,
 	has_streaming => 1);
-$node_standby_2->start;
+start_standby_and_wait($node_master, $node_standby_2);
 
 # Create standby3 linking to master
 my $node_standby_3 = get_new_node('standby3');
 $node_standby_3->init_from_backup($node_master, $backup_name,
 	has_streaming => 1);
-$node_standby_3->start;
+start_standby_and_wait($node_master, $node_standby_3);
 
 # Check that sync_state is determined correctly when
 # synchronous_standby_names is specified in old syntax.
@@ -82,8 +103,10 @@ $node_standby_1->stop;
 $node_standby_2->stop;
 $node_standby_3->stop;
 
-$node_standby_2->start;
-$node_standby_3->start;
+# Make sure that each standby reports back to the primary in
+# the wanted order.
+start_standby_and_wait($node_master, $node_standby_2);
+start_standby_and_wait($node_master, $node_standby_3);
 
 # Specify 2 as the number of sync standbys.
 # Check that two standbys are in 'sync' state.
@@ -94,7 +117,7 @@ standby3|3|sync),
 	'2(standby1,standby2,standby3)');
 
 # Start standby1
-$node_standby_1->start;
+start_standby_and_wait($node_master, $node_standby_1);
 
 # Create standby4 linking to master
 my $node_standby_4 = get_new_node('standby4');
@@ -126,14 +149,16 @@ standby4|1|sync),
 
 # The setting that * comes before another standby name is acceptable
 # but does not make sense in most cases. Check that sync_state is
-# chosen properly even in case of that setting.
-# The priority of standby2 should be 2 because it matches * first.
+# chosen properly even in case of that setting. standby1 is selected
+# as synchronous as it has the highest priority, and is followed by a
+# second standby listed first in the WAL sender array, which is
+# standby2 in this case.
 test_sync_state(
 	$node_master, qq(standby1|1|sync
 standby2|2|sync
 standby3|2|potential
 standby4|2|potential),
-	'asterisk comes before another standby name',
+	'asterisk before another standby name',
 	'2(standby1,*,standby2)');
 
 # Check that the setting of '2(*)' chooses standby2 and standby3 that are stored


signature.asc
Description: PGP signature


Re: Race conditions with TAP test for syncrep

2019-07-22 Thread Noah Misch
On Tue, Jun 18, 2019 at 09:59:08AM +0900, Michael Paquier wrote:
> On Mon, Jun 17, 2019 at 10:50:39AM -0400, Alvaro Herrera wrote:
> > I think this should be note() rather than print(), or maybe diag().  (I
> > see that we have a couple of other cases which use print() in the tap
> > tests, which I think should be note() as well.)
> 
> OK.  Let's change it for this patch.

PostgresNode uses "print" the same way.  The patch does close the intended
race conditions, and its implementation choices look fine to me.




Re: Race conditions with TAP test for syncrep

2019-06-19 Thread Michael Paquier
On Wed, Jun 19, 2019 at 04:08:44PM -0400, Alvaro Herrera wrote:
> Ho ho .. you know what misled me into thinking that that would work?
> Just look at the name of the test that failed, "asterisk comes before
> another standby name".  That doesn't seem to be what the test is
> testing!

I agree that the wording is poor here.  Perhaps a better description
in the comment block would be "standby1 is selected as sync as it has
the highest priority, and is followed by a second standby listed first
in the WAL sender array, in this case standby2".  We could change the
description like that "second standby chosen as sync is the first one
in WAL sender array".  The follow-up test using '2(*)' is actually
worse in terms of ordering dependency as all standbys could be
selected.  The last test with a quorum lookup on all the standbys is
fine from this perspective thanks to the ORDER BY on application_name
when doing the lookup of pg_stat_replication.
--
Michael


signature.asc
Description: PGP signature


Re: Race conditions with TAP test for syncrep

2019-06-19 Thread Alvaro Herrera
On 2019-Jun-18, Michael Paquier wrote:

> On Mon, Jun 17, 2019 at 10:50:39AM -0400, Alvaro Herrera wrote:
> > Hmm, this introduces a bit of latency: it waits for each standby to be
> > fully up before initializing the next standby.  Maybe it would be more
> > convenient to split the primitives: keep the current one to start the
> > standby, and add a separate one to wait for it to be registered.  Then
> > we could do
> > standby1->start;
> > standby2->start;
> > standby3->start;
> > foreach my $sby (@standbys) {
> > $sby->wait_for_standby
> > }
> 
> It seems to me that this sequence could still lead to inconsistencies:
> 1) standby 1 starts, reaches consistency so pg_ctl start -w exits.
> 2) standby 2 starts, reaches consistency.
> 3) standby 2 starts a WAL receiver, gets the first WAL sender slot of
> the primary.
> 4) standby 1 starts a WAL receiver, gets the second slot.

Ho ho .. you know what misled me into thinking that that would work?
Just look at the name of the test that failed, "asterisk comes before
another standby name".  That doesn't seem to be what the test is
testing!

# poll_query_until timed out executing this query:
# SELECT application_name, sync_priority, sync_state FROM pg_stat_replication 
ORDER BY application_name;
# expecting this output:
# standby1|1|sync
# standby2|2|sync
# standby3|2|potential
# standby4|2|potential
# last actual query output:
# standby1|1|sync
# standby2|2|potential
# standby3|2|sync
# standby4|2|potential
# with stderr:

#   Failed test 'asterisk comes before another standby name'

-- 
Álvaro Herrerahttps://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services




Re: Race conditions with TAP test for syncrep

2019-06-17 Thread Michael Paquier
On Mon, Jun 17, 2019 at 10:50:39AM -0400, Alvaro Herrera wrote:
> Hmm, this introduces a bit of latency: it waits for each standby to be
> fully up before initializing the next standby.  Maybe it would be more
> convenient to split the primitives: keep the current one to start the
> standby, and add a separate one to wait for it to be registered.  Then
> we could do
> standby1->start;
> standby2->start;
> standby3->start;
> foreach my $sby (@standbys) {
>   $sby->wait_for_standby
> }

It seems to me that this sequence could still lead to inconsistencies:
1) standby 1 starts, reaches consistency so pg_ctl start -w exits.
2) standby 2 starts, reaches consistency.
3) standby 2 starts a WAL receiver, gets the first WAL sender slot of
the primary.
4) standby 1 starts a WAL receiver, gets the second slot.

> I think this should be note() rather than print(), or maybe diag().  (I
> see that we have a couple of other cases which use print() in the tap
> tests, which I think should be note() as well.)

OK.  Let's change it for this patch.  For the rest, I can always send
a different patch.  Just writing down your comment..
--
Michael


signature.asc
Description: PGP signature


Re: Race conditions with TAP test for syncrep

2019-06-17 Thread Alvaro Herrera
On 2019-Jun-17, Michael Paquier wrote:

> Attached is a patch to improve the stability of the test.  The fix I
> am proposing is very simple: in order to make sure that a standby is
> added into the WAL sender array of the primary, let's check after
> pg_stat_replication after a standby is started.  This can be done
> consistently with a small wrapper in the tests.
> 
> Any thoughts?

Hmm, this introduces a bit of latency: it waits for each standby to be
fully up before initializing the next standby.  Maybe it would be more
convenient to split the primitives: keep the current one to start the
standby, and add a separate one to wait for it to be registered.  Then
we could do
standby1->start;
standby2->start;
standby3->start;
foreach my $sby (@standbys) {
$sby->wait_for_standby
}

so they all start in parallel, saving a bit of time.

> + print "### Waiting for standby \"$standby_name\" on \"$master_name\"\n";

I think this should be note() rather than print(), or maybe diag().  (I
see that we have a couple of other cases which use print() in the tap
tests, which I think should be note() as well.)

-- 
Álvaro Herrerahttps://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services