Merge lp:~rogpeppe/juju-core/359-no-lax into lp:~go-bot/juju-core/trunk

[Roger Peppe]

state: hopefully make tests more reliable

We had a sporadic test failure in MachineSuite.TestWatchMachine:
the last AssertOneChange call received an extra event.

My analysis of the failure goes something like this.
There are two possible scenarios:

scenario 1:

 call Machine.Watch
 remove machine
 StartSync
 state/watcher polls, finds that object has disappeared
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces no value, because there's no object.
 test passes

scenario 2:

 call Machine.Watch
 remove machine
 StartSync
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces a value for the object
 state/watcher polls, finds that object has disappeared
 EntityWatcher receives watcher change and sends to Changes
 test reads unexpected value
 test fails

The problem is that when StartSync returns we have no idea
whether the state/watcher code has started to poll for new
changes or not.

By using Sync instead of StartSync, we ensure that at least
the state/watcher code is in a known state before continuing
to assert whether the watchers built on top of it it will or won't
send events.

The only reason for StartSync's existence, AFAIR, is to avoid
a possible deadlock situation where the state/watcher code
is trying to send on a watcher channel but the test code is
not ready to receive on that channel.

However, in all the places that use NotifyWatcherC and StringsWatcherC,
the state/watcher code is actually sending to a separate goroutine
which is always ready to receive any change. So it's safe
to use Sync rather than StartSync.

I do not understand the "hence cannot verify real-world coalescence behaviour"
comment in the NewLax* functions. If there is coalescence to be verified,
using StartSync rather than Sync is a poor way of verifying it, as
the only allowance that StartSync makes is a few nanoseconds and one or two context
switches - that's not much opportunity for coalescence to happen,
and all tests pass with this CL, which leads me to suspect smoke
and mirrors.

If anyone sees a MachineSuite.TestWatchMachine sporadic failure
with this CL applied, I'd very much like to know, as it means my
analysis is flawed :-).

FWIW, another possibility would be to make StartSync return when
it's certain that the watcher will start a poll before doing anything else.
This would involve a certain amount of restructuring of the
state/watcher code.

https://codereview.appspot.com/12352044/

state: hopefully make tests more reliable

We had a sporadic test failure in MachineSuite.TestWatchMachine:
the last AssertOneChange call received an extra event.

My analysis of the failure goes something like this.
There are two possible scenarios:

scenario 1:

 call Machine.Watch
 remove machine
 StartSync
 state/watcher polls, finds that object has disappeared
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces no value, because there's no object.
 test passes

scenario 2:

 call Machine.Watch
 remove machine
 StartSync
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces a value for the object
 state/watcher polls, finds that object has disappeared
 EntityWatcher receives watcher change and sends to Changes
 test reads unexpected value
 test fails

The problem is that when StartSync returns we have no idea
whether the state/watcher code has started to poll for new
changes or not.

By using Sync instead of StartSync, we ensure that at least
the state/watcher code is in a known state before continuing
to assert whether the watchers built on top of it it will or won't
send events.

The only reason for StartSync's existence, AFAIR, is to avoid
a possible deadlock situation where the state/watcher code
is trying to send on a watcher channel but the test code is
not ready to receive on that channel.

However, in all the places that use NotifyWatcherC and StringsWatcherC,
the state/watcher code is actually sending to a separate goroutine
which is always ready to receive any change. So it's safe
to use Sync rather than StartSync.

I do not understand the "hence cannot verify real-world coalescence behaviour"
comment in the NewLax* functions. If there is coalescence to be verified,
using StartSync rather than Sync is a poor way of verifying it, as
the only allowance that StartSync makes is a few nanoseconds and one or two context
switches - that's not much opportunity for coalescence to happen,
and all tests pass with this CL, which leads me to suspect smoke
and mirrors.

If anyone sees a MachineSuite.TestWatchMachine sporadic failure
with this CL applied, I'd very much like to know, as it means my
analysis is flawed :-).

FWIW, another possibility would be to make StartSync return when
it's certain that the watcher will start a poll before doing anything else.
This would involve a certain amount of restructuring of the
state/watcher code.

https://codereview.appspot.com/12352044/

[Roger Peppe (rogpeppe)]

Reviewers: mp+178357_code.launchpad.net,

Message:
Please take a look.

Description:
state: hopefully make tests more reliable

We had a sporadic test failure in MachineSuite.TestWatchMachine:
the last AssertOneChange call received an extra event.

My analysis of the failure goes something like this.
There are two possible scenarios:

scenario 1:

 call Machine.Watch
 remove machine
 StartSync
 state/watcher polls, finds that object has disappeared
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces no value, because there's no object.
 test passes

scenario 2:

 call Machine.Watch
 remove machine
 StartSync
 EntityWatcher asks to watch object
 EntityWatcher sends initial value on channel
 state/watcher produces a value for the object
 state/watcher polls, finds that object has disappeared
 EntityWatcher receives watcher change and sends to Changes
 test reads unexpected value
 test fails

The problem is that when StartSync returns we have no idea
whether the state/watcher code has started to poll for new
changes or not.

By using Sync instead of StartSync, we ensure that at least
the state/watcher code is in a known state before continuing
to assert whether the watchers built on top of it it will or won't
send events.

The only reason for StartSync's existence, AFAIR, is to avoid
a possible deadlock situation where the state/watcher code
is trying to send on a watcher channel but the test code is
not ready to receive on that channel.

However, in all the places that use NotifyWatcherC and StringsWatcherC,
the state/watcher code is actually sending to a separate goroutine
which is always ready to receive any change. So it's safe
to use Sync rather than StartSync.

I do not understand the "hence cannot verify real-world coalescence
behaviour"
comment in the NewLax* functions. If there is coalescence to be
verified,
using StartSync rather than Sync is a poor way of verifying it, as
the only allowance that StartSync makes is a few nanoseconds and one or
two context
switches - that's not much opportunity for coalescence to happen,
and all tests pass with this CL, which leads me to suspect smoke
and mirrors.

If anyone sees a MachineSuite.TestWatchMachine sporadic failure
with this CL applied, I'd very much like to know, as it means my
analysis is flawed :-).

FWIW, another possibility would be to make StartSync return when
it's certain that the watcher will start a poll before doing anything
else.
This would involve a certain amount of restructuring of the
state/watcher code.

https://code.launchpad.net/~rogpeppe/juju-core/359-no-lax/+merge/178357

(do not edit description out of merge proposal)

Please review this at https://codereview.appspot.com/12352044/

Affected files:
   A [revision details]
   M state/machine_test.go
   M state/service_test.go
   M state/state_test.go
   M state/testing/watcher.go
   M state/unit_test.go

Index: [revision details]
=== added file '[revision details]'
--- [revision details] 2012-01-01 00:00:00 +0000
+++ [revision details] 2012-01-01 00:00:00 +0000
@@ -0,0 +1,2 @@
+Old revision: tarmac-20130802141811-3fnqb3k4j8yz9ea8
+New revision: roger.peppe@canonical...

[Dimiter Naydenov (dimitern)]

Nice catch! LGTM.

https://codereview.appspot.com/12352044/

[Martin Packman (gz)]

LGTM. If I understand this proposal correctly, it should also fix the
bug I just filed due to a failure on the bot, even though that test was
not touched here:

<https://bugs.launchpad.net/juju-core/+bug/1209344>

https://codereview.appspot.com/12352044/

[Andrew Wilkins (axwalk)]

On 2013/08/02 18:37:40, rog wrote:
> Please take a look.

Unnecessary now, but I had a closer look this morning and LGTM.

https://codereview.appspot.com/12352044/

=== modified file 'state/machine_test.go'
--- state/machine_test.go	2013-07-31 14:19:29 +0000
+++ state/machine_test.go	2013-08-02 18:36:32 +0000
@@ -598,7 +598,7 @@
 	// Start a watch on an empty machine; check no units reported.
 	w := s.machine.WatchPrincipalUnits()
 	defer testing.AssertStop(c, w)
-	wc := testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc := testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange()
 	wc.AssertNoChange()
 
@@ -668,7 +668,7 @@
 	// Start a fresh watcher; check both principals reported.
 	w = s.machine.WatchPrincipalUnits()
 	defer testing.AssertStop(c, w)
-	wc = testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc = testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange("mysql/0", "mysql/1")
 	wc.AssertNoChange()
 
@@ -693,7 +693,7 @@
 	// Start a watch on an empty machine; check no units reported.
 	w := s.machine.WatchUnits()
 	defer testing.AssertStop(c, w)
-	wc := testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc := testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange()
 	wc.AssertNoChange()
 
@@ -763,7 +763,7 @@
 	// Start a fresh watcher; check all units reported.
 	w = s.machine.WatchUnits()
 	defer testing.AssertStop(c, w)
-	wc = testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc = testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange("mysql/0", "mysql/1", "logging/0")
 	wc.AssertNoChange()
 

=== modified file 'state/service_test.go'
--- state/service_test.go	2013-07-18 16:46:59 +0000
+++ state/service_test.go	2013-08-02 18:36:32 +0000
@@ -1292,7 +1292,7 @@
 	// TODO(fwereade) split this test up a bit.
 	w := s.mysql.WatchRelations()
 	defer testing.AssertStop(c, w)
-	wc := testing.StringsWatcherC{c, s.State, w, false}
+	wc := testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange()
 	wc.AssertNoChange()
 
@@ -1335,7 +1335,7 @@
 	rel2 := addRelation()
 	w = s.mysql.WatchRelations()
 	defer testing.AssertStop(c, w)
-	wc = testing.StringsWatcherC{c, s.State, w, false}
+	wc = testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange(rel1.String(), rel2.String())
 	wc.AssertNoChange()
 

=== modified file 'state/state_test.go'
--- state/state_test.go	2013-08-01 15:41:09 +0000
+++ state/state_test.go	2013-08-02 18:36:32 +0000
@@ -1722,7 +1722,7 @@
 	// Check initial event.
 	w := s.State.WatchCleanups()
 	defer statetesting.AssertStop(c, w)
-	wc := statetesting.NewLaxNotifyWatcherC(c, s.State, w)
+	wc := statetesting.NewNotifyWatcherC(c, s.State, w)
 	wc.AssertOneChange()
 
 	// Set up two relations for later use, check no events.
@@ -1768,7 +1768,7 @@
 	// Check initial event.
 	w := s.State.WatchCleanups()
 	defer statetesting.AssertStop(c, w)
-	wc := statetesting.NewLaxNotifyWatcherC(c, s.State, w)
+	wc := statetesting.NewNotifyWatcherC(c, s.State, w)
 	wc.AssertOneChange()
 
 	// Create two peer relations by creating their services.
@@ -1799,7 +1799,7 @@
 	// Check initial event.
 	w := s.State.WatchMinUnits()
 	defer statetesting.AssertStop(c, w)
-	wc := statetesting.NewLaxStringsWatcherC(c, s.State, w)
+	wc := statetesting.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange()
 	wc.AssertNoChange()
 

=== modified file 'state/testing/watcher.go'
--- state/testing/watcher.go	2013-07-22 10:29:03 +0000
+++ state/testing/watcher.go	2013-08-02 18:36:32 +0000
@@ -51,9 +51,8 @@
 // the behaviour of any watcher that uses a <-chan struct{}.
 type NotifyWatcherC struct {
 	*C
-	State    *state.State
-	Watcher  NotifyWatcher
-	FullSync bool
+	State   *state.State
+	Watcher NotifyWatcher
 }
 
 // NewNotifyWatcherC returns a NotifyWatcherC that checks for aggressive
@@ -66,20 +65,8 @@
 	}
 }
 
-// NewLaxNotifyWatcherC returns a NotifyWatcherC that runs a full watcher
-// sync before reading from the watcher's Changes channel, and hence cannot
-// verify real-world coalescence behaviour.
-func NewLaxNotifyWatcherC(c *C, st *state.State, w NotifyWatcher) NotifyWatcherC {
-	return NotifyWatcherC{
-		C:        c,
-		State:    st,
-		Watcher:  w,
-		FullSync: true,
-	}
-}
-
 func (c NotifyWatcherC) AssertNoChange() {
-	c.State.StartSync()
+	c.State.Sync()
 	select {
 	case _, ok := <-c.Watcher.Changes():
 		c.Fatalf("watcher sent unexpected change: (_, %v)", ok)
@@ -88,11 +75,7 @@
 }
 
 func (c NotifyWatcherC) AssertOneChange() {
-	if c.FullSync {
-		c.State.Sync()
-	} else {
-		c.State.StartSync()
-	}
+	c.State.Sync()
 	select {
 	case _, ok := <-c.Watcher.Changes():
 		c.Assert(ok, Equals, true)
@@ -115,9 +98,8 @@
 // the behaviour of any watcher that uses a <-chan []string.
 type StringsWatcherC struct {
 	*C
-	State    *state.State
-	Watcher  StringsWatcher
-	FullSync bool
+	State   *state.State
+	Watcher StringsWatcher
 }
 
 // NewStringsWatcherC returns a StringsWatcherC that checks for aggressive
@@ -130,25 +112,13 @@
 	}
 }
 
-// NewLaxStringsWatcherC returns a StringsWatcherC that runs a full watcher
-// sync before reading from the watcher's Changes channel, and hence cannot
-// verify real-world coalescence behaviour.
-func NewLaxStringsWatcherC(c *C, st *state.State, w StringsWatcher) StringsWatcherC {
-	return StringsWatcherC{
-		C:        c,
-		State:    st,
-		Watcher:  w,
-		FullSync: true,
-	}
-}
-
 type StringsWatcher interface {
 	Stop() error
 	Changes() <-chan []string
 }
 
 func (c StringsWatcherC) AssertNoChange() {
-	c.State.StartSync()
+	c.State.Sync()
 	select {
 	case actual, ok := <-c.Watcher.Changes():
 		c.Fatalf("watcher sent unexpected change: (%v, %v)", actual, ok)
@@ -159,11 +129,7 @@
 // AssertChange asserts the given list of changes was reported by
 // the watcher, but does not assume there are no following changes.
 func (c StringsWatcherC) AssertChange(expect ...string) {
-	if c.FullSync {
-		c.State.Sync()
-	} else {
-		c.State.StartSync()
-	}
+	c.State.Sync()
 	timeout := time.After(testing.LongWait)
 	var actual []string
 loop:

=== modified file 'state/unit_test.go'
--- state/unit_test.go	2013-07-31 14:19:29 +0000
+++ state/unit_test.go	2013-08-02 18:36:32 +0000
@@ -953,7 +953,7 @@
 func (s *UnitSuite) TestWatchSubordinates(c *C) {
 	w := s.unit.WatchSubordinateUnits()
 	defer testing.AssertStop(c, w)
-	wc := testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc := testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange()
 	wc.AssertNoChange()
 
@@ -1006,7 +1006,7 @@
 	// Start a new watch, check Dead unit is reported.
 	w = s.unit.WatchSubordinateUnits()
 	defer testing.AssertStop(c, w)
-	wc = testing.NewLaxStringsWatcherC(c, s.State, w)
+	wc = testing.NewStringsWatcherC(c, s.State, w)
 	wc.AssertChange(subUnits[0].Name())
 	wc.AssertNoChange()