Uploaded image for project: 'Thrift'
  1. Thrift
  2. THRIFT-4243

Go TSimpleServer race on wait in Stop() method

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.11.0
    • Component/s: Go - Library
    • Labels:
      None

      Description

      Synchronization issues with the use of sync.WaitGroup in the TSimpleServer implementation set off the race detector. Note the docs (https://godoc.org/sync#WaitGroup.Add) specify "calls with a positive delta that occur when the counter is zero must happen before a Wait".

      The following unit test demonstrates the issue:

      package thrift
      
      import (
      	"testing"
      	"time"
      )
      
      type mockProcessor struct {
      	ProcessFunc func(in, out TProtocol) (bool, TException)
      }
      
      func (m *mockProcessor) Process(in, out TProtocol) (bool, TException) {
      	return m.ProcessFunc(in, out)
      }
      
      type mockServerTransport struct {
      	ListenFunc    func() error
      	AcceptFunc    func() (TTransport, error)
      	CloseFunc     func() error
      	InterruptFunc func() error
      }
      
      func (m *mockServerTransport) Listen() error {
      	return m.ListenFunc()
      }
      
      func (m *mockServerTransport) Accept() (TTransport, error) {
      	return m.AcceptFunc()
      }
      
      func (m *mockServerTransport) Close() error {
      	return m.CloseFunc()
      }
      
      func (m *mockServerTransport) Interrupt() error {
      	return m.InterruptFunc()
      }
      
      type mockTTransport struct {
      	TTransport
      }
      
      func (m *mockTTransport) Close() error {
      	return nil
      }
      
      func TestWaitRace(t *testing.T) {
      	proc := &mockProcessor{
      		ProcessFunc: func(in, out TProtocol) (bool, TException) {
      			return false, nil
      		},
      	}
      
      	trans := &mockServerTransport{
      		ListenFunc: func() error {
      			return nil
      		},
      		AcceptFunc: func() (TTransport, error) {
      			return &mockTTransport{}, nil
      		},
      		CloseFunc: func() error {
      			return nil
      		},
      		InterruptFunc: func() error {
      			return nil
      		},
      	}
      
      	serv := NewTSimpleServer2(proc, trans)
      	go serv.Serve()
      	time.Sleep(1)
      	serv.Stop()
      }
      

      When run with the race detector, this test produces the following output:

      go test -race -v -run TestWaitRace -count 1
      === RUN   TestWaitRace
      ==================
      WARNING: DATA RACE
      Write at 0x00c4200849f4 by goroutine 6:
        internal/race.Write()
            /usr/local/Cellar/go/1.8/libexec/src/internal/race/race.go:41 +0x38
        sync.(*WaitGroup).Wait()
            /usr/local/Cellar/go/1.8/libexec/src/sync/waitgroup.go:129 +0x14b
        git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).Stop.func1()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:164 +0x9b
        sync.(*Once).Do()
            /usr/local/Cellar/go/1.8/libexec/src/sync/once.go:44 +0xe1
        git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).Stop()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:166 +0x8c
        git.apache.org/thrift.git/lib/go/thrift.TestWaitRace()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server_test.go:134 +0x1be
        testing.tRunner()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:657 +0x107
      
      Previous read at 0x00c4200849f4 by goroutine 7:
        internal/race.Read()
            /usr/local/Cellar/go/1.8/libexec/src/internal/race/race.go:37 +0x38
        sync.(*WaitGroup).Add()
            /usr/local/Cellar/go/1.8/libexec/src/sync/waitgroup.go:71 +0x26b
        git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).AcceptLoop()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:139 +0xa6
        git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).Serve()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:154 +0x86
      
      Goroutine 6 (running) created at:
        testing.(*T).Run()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:697 +0x543
        testing.runTests.func1()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:882 +0xaa
        testing.tRunner()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:657 +0x107
        testing.runTests()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:888 +0x4e0
        testing.(*M).Run()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:822 +0x1c3
        main.main()
            git.apache.org/thrift.git/lib/go/thrift/_test/_testmain.go:266 +0x20f
      
      Goroutine 7 (running) created at:
        git.apache.org/thrift.git/lib/go/thrift.TestWaitRace()
            /Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server_test.go:132 +0x1a3
        testing.tRunner()
            /usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:657 +0x107
      ==================
      --- FAIL: TestWaitRace (0.15s)
      	testing.go:610: race detected during execution of test
      panic: sync: WaitGroup is reused before previous Wait has returned [recovered]
      	panic: sync: WaitGroup is reused before previous Wait has returned
      
      goroutine 5 [running]:
      testing.tRunner.func1(0xc42006aea0)
      	/usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:622 +0x55f
      panic(0x14aea60, 0xc4201896a0)
      	/usr/local/Cellar/go/1.8/libexec/src/runtime/panic.go:489 +0x2f0
      sync.(*WaitGroup).Wait(0xc4200849e8)
      	/usr/local/Cellar/go/1.8/libexec/src/sync/waitgroup.go:133 +0x138
      git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).Stop.func1()
      	/Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:164 +0x9c
      sync.(*Once).Do(0x174ce68, 0xc42002bf00)
      	/usr/local/Cellar/go/1.8/libexec/src/sync/once.go:44 +0xe2
      git.apache.org/thrift.git/lib/go/thrift.(*TSimpleServer).Stop(0xc420084980, 0x153af90, 0xc420084980)
      	/Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server.go:166 +0x8d
      git.apache.org/thrift.git/lib/go/thrift.TestWaitRace(0xc42006aea0)
      	/Users/zwass/dev/go/src/git.apache.org/thrift.git/lib/go/thrift/simple_server_test.go:134 +0x1bf
      testing.tRunner(0xc42006aea0, 0x153b2b0)
      	/usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:657 +0x108
      created by testing.(*T).Run
      	/usr/local/Cellar/go/1.8/libexec/src/testing/testing.go:697 +0x544
      exit status 2
      FAIL	git.apache.org/thrift.git/lib/go/thrift	0.190s
      

        Attachments

          Activity

            People

            • Assignee:
              zwass Zach Wasserman
              Reporter:
              zwass Zach Wasserman
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: