Skip to content

Conversation

@djlovell
Copy link

@djlovell djlovell commented Apr 14, 2025

Issue

In my day job, we utilize goworker in a way such that workers are created programatically on the fly (supporting an event bus between different parts of our platform), not just in an init function (as shown in quick start guide. Several of these are generated as part of a common initialization called from:

  1. main.go
  2. nearly every single unit test

Periodically, we observe a fatal error: concurrent map writes error in our automated test suite. We traced it down to the global workers map and unprotected Register function in workers.go, and the fact that Go tests are executed in Goroutines. We permit Go's default behavior of running tests from different packages in parallel, and had to introduce a mutex to the section of our code booting go workers.

log output from new test showing the problem using Go's race detector

me@macbookpro goworker % go test -race -run TestRegister                                
==================
WARNING: DATA RACE
Write at 0x00c000101320 by goroutine 18:
  runtime.mapaccess2_faststr()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/runtime/map_faststr.go:117 +0x42c
  github.com/benmanns/goworker.Register()
      /Users/me/git/goworker/workers.go:21 +0x64
  github.com/benmanns/goworker.TestRegister.func2.gowrap1()
      /Users/me/git/goworker/worker_test.go:95 +0x20

Previous write at 0x00c000101320 by goroutine 12:
  runtime.mapaccess2_faststr()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/runtime/map_faststr.go:117 +0x42c
  github.com/benmanns/goworker.Register()
      /Users/me/git/goworker/workers.go:21 +0x64
  github.com/benmanns/goworker.TestRegister.func2.gowrap1()
      /Users/me/git/goworker/worker_test.go:95 +0x20

Goroutine 18 (running) created at:
  github.com/benmanns/goworker.TestRegister.func2()
      /Users/me/git/goworker/worker_test.go:95 +0x34
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1690 +0x184
  testing.(*T).Run.gowrap1()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1743 +0x40

Goroutine 12 (finished) created at:
  github.com/benmanns/goworker.TestRegister.func2()
      /Users/me/git/goworker/worker_test.go:95 +0x34
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1690 +0x184
  testing.(*T).Run.gowrap1()
      /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1743 +0x40
==================
fatal error: concurrent map writes
fatal error: concurrent map writes

goroutine 12 [running]:
github.com/benmanns/goworker.Register(...)
        /Users/me/git/goworker/workers.go:21
created by github.com/benmanns/goworker.TestRegister.func2 in goroutine 8
        /Users/me/git/goworker/worker_test.go:95 +0x38

goroutine 1 [chan receive]:
testing.(*T).Run(0xc0001069c0, {0x102d7a274, 0xc}, 0x102ea0578)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1751 +0x600
testing.runTests.func1(0xc0001069c0)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:2168 +0x84
testing.tRunner(0xc0001069c0, 0xc000145ad8)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1690 +0x188
testing.runTests(0xc00000c330, {0x1030a05c0, 0x9, 0x9}, {0xc0001012f0?, 0x102b135f0?, 0x1030a66c0?})
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:2166 +0x6e4
testing.(*M).Run(0xc00010adc0)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:2034 +0xb78
main.main()
        _testmain.go:61 +0x114

goroutine 4 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc000010710, 0x0)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/runtime/sema.go:587 +0x154
sync.(*Cond).Wait(0xc000010700)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/sync/cond.go:71 +0x6c
github.com/cihub/seelog.(*asyncLoopLogger).processItem(0xc00010e1e0)
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:50 +0x120
github.com/cihub/seelog.(*asyncLoopLogger).processQueue(...)
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:63
created by github.com/cihub/seelog.newAsyncLoopLogger in goroutine 1
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:40 +0xf8

goroutine 5 [sync.Cond.Wait]:
sync.runtime_notifyListWait(0xc000010890, 0x0)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/runtime/sema.go:587 +0x154
sync.(*Cond).Wait(0xc000010880)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/sync/cond.go:71 +0x6c
github.com/cihub/seelog.(*asyncLoopLogger).processItem(0xc00010e300)
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:50 +0x120
github.com/cihub/seelog.(*asyncLoopLogger).processQueue(...)
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:63
created by github.com/cihub/seelog.newAsyncLoopLogger in goroutine 1
        /Users/me/go/pkg/mod/github.com/cihub/seelog@v0.0.0-20140730094913-72ae425987bc/behavior_asynclooplogger.go:40 +0xf8

goroutine 6 [runnable]:
sync.(*Pool).pin(0x10309b300)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/sync/pool.go:202 +0xc0
sync.(*Pool).Put(0x10309b300, {0x102e939a0, 0xc00028e000})
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/sync/pool.go:111 +0x60
fmt.(*pp).free(0xc00028e000)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/fmt/print.go:181 +0x158
fmt.Sprintf({0x102d857c3, 0x26}, {0x0, 0x0, 0x0})
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/fmt/print.go:241 +0x8c
testing.(*common).Errorf(0xc000106b60, {0x102d857c3, 0x26}, {0x0, 0x0, 0x0})
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1075 +0x70
testing.(*common).checkRaces(0xc000106b60)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1399 +0x98
testing.tRunner.func1()
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1548 +0x3c
testing.tRunner(0xc000106b60, 0x102ea0578)
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1696 +0x1b0
created by testing.(*T).Run in goroutine 1
        /opt/homebrew/Cellar/go/1.23.0/libexec/src/testing/testing.go:1743 +0x5e4

goroutine 11 [running]:
        goroutine running on other thread; stack unavailable
created by github.com/benmanns/goworker.TestRegister.func2 in goroutine 8
        /Users/me/git/goworker/worker_test.go:95 +0x38

goroutine 11 [running]:
github.com/benmanns/goworker.Register(...)
        /Users/me/git/goworker/workers.go:21
created by github.com/benmanns/goworker.TestRegister.func2 in goroutine 8
        /Users/me/git/goworker/worker_test.go:95 +0x38
exit status 2
FAIL    github.com/benmanns/goworker    0.508s

Proposal

Use a mutex to restrict access to workers.

@djlovell djlovell marked this pull request as ready for review April 14, 2025 20:43
@benmanns benmanns merged commit f3aeb48 into benmanns:master Apr 15, 2025
21 of 39 checks passed
@benmanns
Copy link
Owner

Looks great, thanks! I will admit I hadn't thought of that use case as my workers have always been known at compile time.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants