TestHashRing+TestServiceWithMockDal fail go test -race

[alecthomas]

TestHashRing and TestServiceWithMockDal fail the race detector. It's disabled for now, but needs to be fixed and reenabled.

[matt2e]

Reopening, hit this case:

panic: test timed out after 10m0s
running tests:
	TestServiceWithMockDal (10m0s)

[matt2e]

Error report is here https://github.com/TBD54566975/ftl/actions/runs/8903975228/job/24452548713?pr=1360

From what I can tell TestServiceWithMockDal is getting stuck in benbjohnson/clock somehow

The main test function is blocked trying to advance the mock clock but is getting stuck when sending a message to its channel:

goroutine 34 [chan send, 9 minutes]:
github.com/benbjohnson/clock.(*internalTimer).Tick(0xc0000e2aa0, {0xe7791f704?, 0xd57b60?, 0xd57b60?})
	/home/runner/go/pkg/mod/github.com/benbjohnson/[email protected]/clock.go:353 +0x185
github.com/benbjohnson/clock.(*Mock).runNextTimer(0xc0001b23c0, {0xe7791f705?, 0xd57b60?, 0xd57b60?})
	/home/runner/go/pkg/mod/github.com/benbjohnson/[email protected]/clock.go:179 +0x1f2
github.com/benbjohnson/clock.(*Mock).Add(0xc0001b23c0, 0x77359400)
	/home/runner/go/pkg/mod/github.com/benbjohnson/[email protected]/clock.go:101 +0x9e
github.com/TBD54566975/ftl/backend/controller/cronjobs.testServiceWithDal({0xa8e1e8, 0xc0000246e0}, 0xc0000bc9c0, {0xa8f4b0, 0xc00021e080}, {0xa90f30, 0xc0001b23c0})
	/home/runner/work/ftl/ftl/backend/controller/cronjobs/cronjobs_utils_test.go:248 +0x6de
github.com/TBD54566975/ftl/backend/controller/cronjobs.TestServiceWithMockDal(0xc0000bc9c0)
	/home/runner/work/ftl/ftl/backend/controller/cronjobs/cronjobs_test.go:38 +0x237
testing.tRunner(0xc0000bc9c0, 0xa0e470)
	/home/runner/.cache/hermit/pkg/go-1.22.2/src/testing/testing.go:1[68](https://github.com/TBD54566975/ftl/actions/runs/8903975228/job/24452548713?pr=1360#step:7:69)9 +0x21f
created by testing.(*T).Run in goroutine 1
	/home/runner/.cache/hermit/pkg/go-1.22.2/src/testing/testing.go:1742 +0x826

While a bunch of other goroutines are blocked trying to access clock.Now() but can't get a lock (internal to benbjohnson/clock)

From clock.go

// This should only be called from a single goroutine at a time.
func (m *Mock) Add(d time.Duration) {

We adhere to this fine, this is the only place we are advancing the clock in this test: cronjobs_utils_test.go#L248
And I can't see any other notes of things to be careful about with multiple go routines

I think what is happening is:
(prefixing each step with its goroutine, either :

• A: the goroutine the test is running in)
• B: the goroutine that cronjobs.go is watching in

Steps:

• B: cronjobs.go waits for signals from the mock clock, among other things
• A: We try to increment the mock clock
  • it gets a lock on the mock clock's mutex
• B: [race condition] cronjobs.go tries to access Now(), blocks because it can't get a lock
• A: the mock clock tries to push the new time to the channel clock.go#L353
  • This blocks the mock clock because the listener is not ready to start receiving
• [A+B] ... deadlock

I haven't got a solid footing in goroutines/channels yet, so I may have missed something

Also FYI, the clock library has been archived for about a year now:

• authors reason is here: Fix race condition on 'now' when creating a timer benbjohnson/clock#58 (comment)

[matt2e]

Closing for now. Test is skipped, and integration test tests the same thing with the real db

[gak]

Just saw this on my PR. I restarted the job which worked. https://github.com/TBD54566975/ftl/actions/runs/9090895040/attempts/1