Skip to content

fix: race panic in test/go/postgres #1752

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 1 commit into from
Closed

Conversation

coadler
Copy link
Contributor

@coadler coadler commented May 25, 2022

https://github.com/coder/coder/actions/runs/2359166491/attempts/1

The current race condition is caused by a call to t.Log at the same time a test is finishing. This PR changes the logger to be swapped out before tests exit, to avoid any logs that may race with a test finishing.

@coadler coadler self-assigned this May 25, 2022
@coadler coadler linked an issue May 25, 2022 that may be closed by this pull request
@coadler coadler marked this pull request as ready for review May 25, 2022 18:30
@coadler coadler requested review from kylecarbs and dwahler May 25, 2022 18:31
@dwahler
Copy link
Contributor

dwahler commented May 25, 2022

I think this change would reduce the probability of a race, but not completely eliminate it.

In the current version of the code, the goroutine that generates the log message is reading coderd.options.Logger, then calling Debug() on it which eventually calls t.Log(). Making Logger an atomic reference and clearing it during cleanup doesn't fix this, because a concurrently running goroutine might read the value of Logger before it's cleared, but then call t.Log() after the test exits.

Here's a minimal example that demonstrates the same issue. It succeeds on the playground, but fails if run with -race -count=100.

I think fixing this properly requires pushing the synchronization all the way to slogtest.testSink. Something like:

type testSink struct {
    tb testing.TB
    mutex sync.Mutex
    testDone bool
}

@coadler
Copy link
Contributor Author

coadler commented May 25, 2022

I looked into doing something like that as my first option, but how would the test sink know when the test exits?

@coadler
Copy link
Contributor Author

coadler commented May 25, 2022

Hmm, I guess maybe if the sink had its own t.Cleanup that set the flag that would work?

@dwahler
Copy link
Contributor

dwahler commented May 25, 2022

Yeah, at first I was thinking we'd have to make slogtest.Make return an extra function/object/something to provide a way for the test code to signal that it was done, but just having the sink register its own cleanup function is much more elegant.

@coadler
Copy link
Contributor Author

coadler commented May 25, 2022

Closing in favor of coder/slog#146 and #1759

@coadler coadler closed this May 25, 2022
@coadler coadler deleted the colin/fix-test-race branch May 25, 2022 20:49
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.

2 participants