Skip to content
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

Deadlock when calling BufferedWriteSyncer.Stop #1428

Closed
Gordy96 opened this issue Apr 11, 2024 · 1 comment · Fixed by #1430
Closed

Deadlock when calling BufferedWriteSyncer.Stop #1428

Gordy96 opened this issue Apr 11, 2024 · 1 comment · Fixed by #1430

Comments

@Gordy96
Copy link

Gordy96 commented Apr 11, 2024

Describe the bug

Upon calling Stop there's a small chance of deadlock. Happens sometimes on go v1.21.3 zap v1.22.0.

To Reproduce

Can't really figure out how to reproduce it without touching said code yet.

This is what I suspect is happening:

When Stop is called, it spawns a goroutine that locks mutex,

s.mu.Lock()
defer s.mu.Unlock()

stops timer and tells flushLoop to break
s.ticker.Stop()
close(s.stop) // tell flushLoop to stop
<-s.done // and wait until it has

However if timer fired before stop occurred here
select {
case <-s.ticker.C:
// we just simply ignore error here
// because the underlying bufio writer stores any errors
// and we return any error from Sync() as part of the close
_ = s.Sync()
case <-s.stop:
return
}

It calls Sync that tries to acuire locked mutex
s.mu.Lock()
defer s.mu.Unlock()

So Stop goroutine holds mutex and waits for flushLoop to close channel on defer while flushLoop waits on Sync to finish, but it can't since mutex is locked in Stop goroutine

prashantv added a commit that referenced this issue Apr 12, 2024
Fixes #1428.

Stop signals the flush loop to end, but if the flush ticker has fired
after we took the lock, then it tries to `Sync`, and waits for the same
lock that `Stop` is holding. This causes a deadlock, as `Stop` holds the
lock waiting for flush to end.

Fix by waiting for the flush loop to end outside of the critical
section.

We only need to wait (and call Sync) if the write syncer has been
initialized and stopped.
@prashantv
Copy link
Collaborator

Thank you for the detailed bug report, you're exactly right with your analysis, Stop holds the lock, which flushLoop will also try to acquire if the timer ticks around the same time. I was able to reproduce it consistently with the added test in #1430, and verified that it fixes the issue.

prashantv added a commit that referenced this issue Apr 13, 2024
Fixes #1428.

Stop signals the flush loop to end, but if the flush ticker has fired
after we took the lock, then it tries to `Sync`, and waits for the same
lock that `Stop` is holding. This causes a deadlock, as `Stop` holds the
lock waiting for flush to end.

Fix by waiting for the flush loop to end outside of the critical section.

We only need to wait (and call Sync) if the write syncer has been
initialized and stopped.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging a pull request may close this issue.

2 participants