(*logsinkSuite).SetUpTest data race

Bug #1755796 reported by John A Meinel on 2018-03-14
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
juju
High
John A Meinel
2.3
High
John A Meinel

Bug Description

github.com/juju/juju/apiserver/logsink_test.(*logsinkSuite).SetUpTest has a Data Race in develop:
http://10.125.0.203:8080/job/RunUnittests-race-amd64/182/testReport/junit/github/com_juju_juju_apiserver_logsink/TestPackage/

WARNING: DATA RACE
Write at 0x00c4200d0210 by goroutine 70:
  github.com/juju/juju/apiserver/logsink_test.(*logsinkSuite).SetUpTest.func1()
      /workspace/src/github.com/juju/juju/apiserver/logsink/logsink_test.go:68 +0xc1
  github.com/juju/juju/apiserver/logsink_test.(*mockLogWriteCloser).Close()
      /workspace/src/github.com/juju/juju/apiserver/logsink/logsink_test.go:265 +0x129
  github.com/juju/juju/apiserver/logsink.(*logSinkHandler).ServeHTTP.func1()
      /workspace/src/github.com/juju/juju/apiserver/logsink/logsink.go:163 +0x5c3
  github.com/juju/juju/apiserver/websocket.Serve()
      /workspace/src/github.com/juju/juju/apiserver/websocket/websocket.go:64 +0x1b1
  github.com/juju/juju/apiserver/logsink.(*logSinkHandler).ServeHTTP()
      /workspace/src/github.com/juju/juju/apiserver/logsink/logsink.go:168 +0xba
  net/http.serverHandler.ServeHTTP()
      /snap/go/1404/src/net/http/server.go:2619 +0xbc
  net/http.(*conn).serve()
      /snap/go/1404/src/net/http/server.go:1801 +0x83b

Previous write at 0x00c4200d0210 by goroutine 75:
  github.com/juju/juju/apiserver/logsink_test.(*logsinkSuite).SetUpTest()
      /workspace/src/github.com/juju/juju/apiserver/logsink/logsink_test.go:63 +0x165
  runtime.call32()
      /snap/go/1404/src/runtime/asm_amd64.s:509 +0x3a
  reflect.Value.Call()
      /snap/go/1404/src/reflect/value.go:302 +0xc0
  gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1()
      /workspace/src/gopkg.in/check.v1/check.go:721 +0x184
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /workspace/src/gopkg.in/check.v1/check.go:666 +0x89

Goroutine 70 (running) created at:
  net/http.(*Server).Serve()
      /snap/go/1404/src/net/http/server.go:2720 +0x37c
  net/http/httptest.(*Server).goServe.func1()
      /snap/go/1404/src/net/http/httptest/server.go:280 +0xa2

Goroutine 75 (finished) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /workspace/src/gopkg.in/check.v1/check.go:663 +0x430
  gopkg.in/check%2ev1.(*suiteRunner).runFunc()
      /workspace/src/gopkg.in/check.v1/check.go:673 +0x7e
  gopkg.in/check%2ev1.(*suiteRunner).runFixture()
      /workspace/src/gopkg.in/check.v1/check.go:717 +0x7e
  gopkg.in/check%2ev1.(*suiteRunner).runFixtureWithPanic()
      /workspace/src/gopkg.in/check.v1/check.go:735 +0xaa
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /workspace/src/gopkg.in/check.v1/check.go:760 +0x217
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /workspace/src/gopkg.in/check.v1/check.go:666 +0x89
==================
OK: 6 passed
 testing.go:699: race detected during execution of test

John A Meinel (jameinel) on 2018-03-14
Changed in juju:
status: Triaged → In Progress
Download full text (4.0 KiB)

SetUpTest first initializes the lastStack to nil, but wasn't doing so using
the stackMu. This should be a reasonable fix:
--- a/apiserver/logsink/logsink_test.go
+++ b/apiserver/logsink/logsink_test.go
@@ -60,7 +60,9 @@ func (s *logsinkSuite) SetUpTest(c *gc.C) {
        s.abort = make(chan struct{})
        s.written = make(chan params.LogRecord, 1)
        s.stub.ResetCalls()
+ s.stackMu.Lock()
        s.lastStack = nil
+ s.stackMu.Unlock()

        recordStack := func() {
                s.stackMu.Lock()

On Wed, Mar 14, 2018 at 4:11 PM, John A Meinel <email address hidden>
wrote:

> Public bug reported:
>
> github.com/juju/juju/apiserver/logsink_test.(*logsinkSuite).SetUpTest has
> a Data Race in develop:
> http://10.125.0.203:8080/job/RunUnittests-race-amd64/182/
> testReport/junit/github/com_juju_juju_apiserver_logsink/TestPackage/
>
> WARNING: DATA RACE
> Write at 0x00c4200d0210 by goroutine 70:
> github.com/juju/juju/apiserver/logsink_test.(*
> logsinkSuite).SetUpTest.func1()
> /workspace/src/github.com/juju/juju/apiserver/logsink/
> logsink_test.go:68 +0xc1
> github.com/juju/juju/apiserver/logsink_test.(*
> mockLogWriteCloser).Close()
> /workspace/src/github.com/juju/juju/apiserver/logsink/
> logsink_test.go:265 +0x129
> github.com/juju/juju/apiserver/logsink.(*logSinkHandler).ServeHTTP.
> func1()
> /workspace/src/github.com/juju/juju/apiserver/logsink/logsink.go:163
> +0x5c3
> github.com/juju/juju/apiserver/websocket.Serve()
> /workspace/src/github.com/juju/juju/apiserver/websocket/
> websocket.go:64 +0x1b1
> github.com/juju/juju/apiserver/logsink.(*logSinkHandler).ServeHTTP()
> /workspace/src/github.com/juju/juju/apiserver/logsink/logsink.go:168
> +0xba
> net/http.serverHandler.ServeHTTP()
> /snap/go/1404/src/net/http/server.go:2619 +0xbc
> net/http.(*conn).serve()
> /snap/go/1404/src/net/http/server.go:1801 +0x83b
>
> Previous write at 0x00c4200d0210 by goroutine 75:
> github.com/juju/juju/apiserver/logsink_test.(*logsinkSuite).SetUpTest()
> /workspace/src/github.com/juju/juju/apiserver/logsink/
> logsink_test.go:63 +0x165
> runtime.call32()
> /snap/go/1404/src/runtime/asm_amd64.s:509 +0x3a
> reflect.Value.Call()
> /snap/go/1404/src/reflect/value.go:302 +0xc0
> gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1()
> /workspace/src/gopkg.in/check.v1/check.go:721 +0x184
> gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
> /workspace/src/gopkg.in/check.v1/check.go:666 +0x89
>
> Goroutine 70 (running) created at:
> net/http.(*Server).Serve()
> /snap/go/1404/src/net/http/server.go:2720 +0x37c
> net/http/httptest.(*Server).goServe.func1()
> /snap/go/1404/src/net/http/httptest/server.go:280 +0xa2
>
> Goroutine 75 (finished) created at:
> gopkg.in/check%2ev1.(*suiteRunner).forkCall()
> /workspace/src/gopkg.in/check.v1/check.go:663 +0x430
> gopkg.in/check%2ev1.(*suiteRunner).runFunc()
> /workspace/src/gopkg.in/check.v1/check.go:673 +0x7e
> gopkg.in/check%2ev1.(*suiteRunner).runFixture()
> /workspace/src/gopkg.in/check.v1/check.go:717 +0x7e
> gopkg.in/check%2ev1.(*suiteRunner).runFixtureW...

Read more...

John A Meinel (jameinel) wrote :

oddly, I can't seem to get it to trigger in my testing, but it is clear that we could be setting the value to nil and someone else would be trying to do something.

John A Meinel (jameinel) wrote :
Changed in juju:
milestone: none → 2.4-beta1
John A Meinel (jameinel) on 2018-03-14
Changed in juju:
status: In Progress → Fix Committed
Changed in juju:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers