(*logsinkSuite).SetUpTest data race

Bug #1755796 reported by John A Meinel
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical Juju
Fix Released
High
John A Meinel
2.3
Fix Released
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)
Changed in juju:
status: Triaged → In Progress
Revision history for this message
John A Meinel (jameinel) wrote : Re: [Bug 1755796] [NEW] (*logsinkSuite).SetUpTest data race
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...

Revision history for this message
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.

Revision history for this message
John A Meinel (jameinel) wrote :
Changed in juju:
milestone: none → 2.4-beta1
John A Meinel (jameinel)
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  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.