state: fix data race in test failure path

state: fix data race in test failure path

Several tests in the state package fail under the race detector, probably because the race detector slows them down a lot. This proposal fixes a data race that occurs if the test fails.

https://code.launchpad.net/~dave-cheney/juju-core/061-state-watcher-fix-race/+merge/139142

(do not edit description out of merge proposal)

[dave_cheney.net, 2012-12-11 05:11:56]

Please take a look.

[fwereade, 2012-12-11 09:29:00]

LGTM pending explanation

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
Would you explain a little more? ISTM that the Stop() in TearDownTest should do
this just fine...

[rog, 2012-12-11 12:18:12]

same as fwereade.

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go
File state/api/serve.go (right):

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go#newcode24
state/api/serve.go:24: // and key (in PEM format) for authentication.
what's going on here? are you using a different version of gofmt?

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
On 2012/12/11 09:29:00, fwereade wrote:
> Would you explain a little more? ISTM that the Stop() in TearDownTest should
do
> this just fine...

+1
i don't see how this makes a difference.

[dave_cheney.net, 2012-12-11 12:22:26]

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go
File state/api/serve.go (right):

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go#newcode24
state/api/serve.go:24: // and key (in PEM format) for authentication.
On 2012/12/11 12:18:12, rog wrote:
> what's going on here? are you using a different version of gofmt?

Trailing whitespace, it is invisible in proportional fonts.

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
On 2012/12/11 12:18:12, rog wrote:
> On 2012/12/11 09:29:00, fwereade wrote:
> > Would you explain a little more? ISTM that the Stop() in TearDownTest should
> do
> > this just fine...
> 
> +1
> i don't see how this makes a difference.

If the test fails, the defer will happen while the watcher is active. The defer
will change the value of log.Debug while the watcher is happily prattling to
itself. This is the data race. If the test completes successfully then the
watcher will have nothing to log.

[rog, 2012-12-11 12:40:00]

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
On 2012/12/11 12:22:27, dfc wrote:
> On 2012/12/11 12:18:12, rog wrote:
> > On 2012/12/11 09:29:00, fwereade wrote:
> > > Would you explain a little more? ISTM that the Stop() in TearDownTest
should
> > do
> > > this just fine...
> > 
> > +1
> > i don't see how this makes a difference.
> 
> If the test fails, the defer will happen while the watcher is active. The
defer
> will change the value of log.Debug while the watcher is happily prattling to
> itself. This is the data race. If the test completes successfully then the
> watcher will have nothing to log.

sorry, i still don't see the issue. TearDownTest stops the watcher before it
calls LoggingSuite.TearDownTest, which is the thing that changes log.Debug.

how does doing s.w.Stop twice in quick succession help here?

[rog, 2012-12-11 12:42:17]

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go
File state/api/serve.go (right):

https://codereview.appspot.com/6930048/diff/1/state/api/serve.go#newcode24
state/api/serve.go:24: // and key (in PEM format) for authentication.
On 2012/12/11 12:22:27, dfc wrote:
> On 2012/12/11 12:18:12, rog wrote:
> > what's going on here? are you using a different version of gofmt?
> 
> Trailing whitespace, it is invisible in proportional fonts.

it's invisible in any font, no?

are you deliberately removing trailing white space in this CL, or is gofmt doing
it automatically? i'd presumed the latter (as this file seems unrelated to the
rest of the CL); if it's the former, then fine, we'll leave as you've proposed
it.

(i'd noticed a similar thing in another CL which was why i brought up the
subject)

[dave_cheney.net, 2012-12-11 12:42:55]

This a gofmt 1.1 vs 1.0 issue.

[rog, 2012-12-11 14:36:01]

On 2012/12/11 12:42:55, dfc wrote:
> This a gofmt 1.1 vs 1.0 issue.

i thought we'd decided to standardise on 1.0.3 gofmt.

[rog, 2012-12-11 14:36:31]

On 2012/12/11 14:36:01, rog wrote:
> On 2012/12/11 12:42:55, dfc wrote:
> > This a gofmt 1.1 vs 1.0 issue.
> 
> i thought we'd decided to standardise on 1.0.3 gofmt.

or perhaps 1.0.2, but i think they're functionally the same.

[dave_cheney.net, 2012-12-13 05:41:59]

> > i thought we'd decided to standardise on 1.0.3 gofmt.
> 
> or perhaps 1.0.2, but i think they're functionally the same.

Looking back at the notes the best I can gather is we decided to support both.
This whitespace change is backwards compatible with go 1.0 gofmt.

[dave_cheney.net, 2012-12-13 05:42:06]

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
> sorry, i still don't see the issue. TearDownTest stops the watcher before it
> calls LoggingSuite.TearDownTest, which is the thing that changes log.Debug.

The problem, I believe, is like 357 races with TearDownTest. By stopping the
watcher, there are no calls to log.Something before the defer runs.

[rog, 2012-12-13 14:45:22]

LGTM with one suggestion.

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
On 2012/12/13 05:42:06, dfc wrote:
> > sorry, i still don't see the issue. TearDownTest stops the watcher before it
> > calls LoggingSuite.TearDownTest, which is the thing that changes log.Debug.
> 
> The problem, I believe, is like 357 races with TearDownTest. By stopping the
> watcher, there are no calls to log.Something before the defer runs.

ah, i hadn't seen line 357 - that makes sense now (i'd assumed it was something
to do with LoggingSuite).

how about putting this defer next to the lines which make it necessary; after
line 358, for example?

[dave_cheney.net, 2012-12-14 07:38:25]

*** Submitted:

state: fix data race in test failure path

Several tests in the state package fail under the race detector, probably
because the race detector slows them down a lot. This proposal fixes a data race
that occurs if the test fails.

R=fwereade, rog
CC=
https://codereview.appspot.com/6930048

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go
File state/watcher/watcher_test.go (right):

https://codereview.appspot.com/6930048/diff/1/state/watcher/watcher_test.go#n...
state/watcher/watcher_test.go:381: defer s.w.Stop()
On 2012/12/13 14:45:22, rog wrote:
> On 2012/12/13 05:42:06, dfc wrote:
> > > sorry, i still don't see the issue. TearDownTest stops the watcher before
it
> > > calls LoggingSuite.TearDownTest, which is the thing that changes
log.Debug.
> > 
> > The problem, I believe, is like 357 races with TearDownTest. By stopping the
> > watcher, there are no calls to log.Something before the defer runs.
> 
> ah, i hadn't seen line 357 - that makes sense now (i'd assumed it was
something
> to do with LoggingSuite).
> 
> how about putting this defer next to the lines which make it necessary; after
> line 358, for example?

Done.