Skip to content

Commit

Permalink
Fix deadlock when Stop and flush race
Browse files Browse the repository at this point in the history
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.
  • Loading branch information
prashantv committed Apr 12, 2024
1 parent b15585b commit 3909ad7
Show file tree
Hide file tree
Showing 2 changed files with 20 additions and 11 deletions.
23 changes: 12 additions & 11 deletions zapcore/buffered_write_syncer.go
Expand Up @@ -188,32 +188,33 @@ func (s *BufferedWriteSyncer) flushLoop() {
// Stop closes the buffer, cleans up background goroutines, and flushes
// remaining unwritten data.
func (s *BufferedWriteSyncer) Stop() (err error) {
var stopped bool

// Critical section.
func() {
stopped := func() bool {
s.mu.Lock()
defer s.mu.Unlock()

if !s.initialized {
return
return false
}

stopped = s.stopped
if stopped {
return
if s.stopped {
return false
}
s.stopped = true

s.ticker.Stop()
close(s.stop) // tell flushLoop to stop
<-s.done // and wait until it has
return true
}()

// Don't call Sync on consecutive Stops.
// Not initialized, or already stopped, no need for any cleanup.
if !stopped {
err = s.Sync()
return
}

return err
// Wait for flushLoop to end outside of the lock, as it may need the lock to complete.
// See https://github.com/uber-go/zap/issues/1428 for details.
<-s.done

return s.Sync()
}
8 changes: 8 additions & 0 deletions zapcore/buffered_write_syncer_test.go
Expand Up @@ -53,6 +53,14 @@ func TestBufferWriter(t *testing.T) {
assert.Equal(t, "foo", buf.String(), "Unexpected log string")
})

t.Run("stop race with flush", func(t *testing.T) {
buf := &bytes.Buffer{}
ws := &BufferedWriteSyncer{WS: AddSync(buf), FlushInterval: 1}
requireWriteWorks(t, ws)
assert.NoError(t, ws.Stop())
assert.Equal(t, "foo", buf.String(), "Unexpected log string")
})

t.Run("stop twice", func(t *testing.T) {
ws := &BufferedWriteSyncer{WS: &ztest.FailWriter{}}
_, err := ws.Write([]byte("foo"))
Expand Down

0 comments on commit 3909ad7

Please sign in to comment.