From 8fab800841f3299a7fa0963c8389c555a9a50834 Mon Sep 17 00:00:00 2001 From: Sean Linsley Date: Wed, 8 Jul 2026 16:52:28 -0400 Subject: [PATCH 1/6] Avoid deadlocks when closing follower --- follower/follower.go | 5 +++- follower/follower_test.go | 48 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 52 insertions(+), 1 deletion(-) diff --git a/follower/follower.go b/follower/follower.go index d6d793b..95cdbb3 100644 --- a/follower/follower.go +++ b/follower/follower.go @@ -57,7 +57,7 @@ func New(filename string, config Config) (*Follower, error) { filename: filename, lines: make(chan Line), config: config, - closeCh: make(chan struct{}), + closeCh: make(chan struct{}, 1), } err := t.reopen() @@ -79,6 +79,9 @@ func (t *Follower) Err() error { } func (t *Follower) Close() { + if t.file != nil { + t.file.Close() + } t.closeCh <- struct{}{} } diff --git a/follower/follower_test.go b/follower/follower_test.go index e84f94f..12ae203 100644 --- a/follower/follower_test.go +++ b/follower/follower_test.go @@ -218,6 +218,54 @@ func TestSymlink(t *testing.T) { assertFollowedLines(t, f, testLines[1]) } +// Regression test for: Close() deadlocks when follow() is blocked in +// the inner read loop (ReadBytes waiting for data). The closeCh select +// is only in the outer loop, so Close() blocks forever on the unbuffered +// closeCh send. +func TestCloseDeadlockNoConsumer(t *testing.T) { + file := testFile(t, "TestCloseDeadlockNoConsumer") + f, err := New(file.Name(), Config{ + Reopen: true, + Offset: 0, + Whence: io.SeekEnd, + }) + if err != nil { + t.Fatal(err) + } + + // Write a partial line (no trailing newline). The follower reads it via + // ReadBytes and blocks waiting for the newline delimiter. There is no + // consumer on f.Lines(), so sendLine would block too, but ReadBytes + // blocks first (it must complete before sendLine can be reached). + if _, err := file.WriteString("partial line"); err != nil { + t.Fatal(err) + } + time.Sleep(100 * time.Millisecond) + + // Close() must return within the deadline. Before the fix it deadlocks. + done := make(chan struct{}) + go func() { + f.Close() + close(done) + }() + select { + case <-done: + case <-time.After(3 * time.Second): + t.Fatal("Close() deadlocked: follow() was blocked in the inner read loop") + } + time.Sleep(100 * time.Millisecond) + + // Verify the lines channel is closed (confirms run() called close()). + select { + case _, ok := <-f.Lines(): + if ok { + t.Fatal("Lines channel should be closed after Close()") + } + case <-time.After(1 * time.Second): + t.Fatal("Lines channel was not closed after Close()") + } +} + func testFile(t *testing.T, name string) *os.File { // open in append mode since most loggers will be doing such file, err := os.OpenFile(path.Join(tmpDir, name), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666) From 8dca37466742d96b37253109112d10d72b5f94b6 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sat, 11 Jul 2026 16:29:29 -0700 Subject: [PATCH 2/6] Rework close channel to use Go channel closure as the signal Reading from a closed channel always returns immediately, and when close gets invoked waiting Go routines are instantly unblocked. This is a more reliable mechanism than using a buffered channel for closeCh, which could theoretically block on a third call to the Follower Close() method. Use sync.Once to ensure the channel is only closed once, since subsequent close calls would otherwise panic. --- follower/follower.go | 25 +++++++++++++------------ 1 file changed, 13 insertions(+), 12 deletions(-) diff --git a/follower/follower.go b/follower/follower.go index 95cdbb3..53bac75 100644 --- a/follower/follower.go +++ b/follower/follower.go @@ -40,16 +40,17 @@ type Config struct { } type Follower struct { - once sync.Once - file *os.File - filename string - lines chan Line - err error - config Config - reader *bufio.Reader - watcher *fsnotify.Watcher - offset int64 - closeCh chan struct{} + once sync.Once + file *os.File + filename string + lines chan Line + err error + config Config + reader *bufio.Reader + watcher *fsnotify.Watcher + offset int64 + closeCh chan struct{} + closeOnce sync.Once } func New(filename string, config Config) (*Follower, error) { @@ -57,7 +58,7 @@ func New(filename string, config Config) (*Follower, error) { filename: filename, lines: make(chan Line), config: config, - closeCh: make(chan struct{}, 1), + closeCh: make(chan struct{}), } err := t.reopen() @@ -82,7 +83,7 @@ func (t *Follower) Close() { if t.file != nil { t.file.Close() } - t.closeCh <- struct{}{} + t.closeOnce.Do(func() { close(t.closeCh) }) } func (t *Follower) run() { From 9b1ff696b4f7479812cc61a4c585de02dcb858a9 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sat, 11 Jul 2026 16:31:31 -0700 Subject: [PATCH 3/6] Don't eagerly close file when calling Follower's Close() method The file is assumed to be owned and only modified by the internally running tail Go routine, and closing the file directly causes a data race, as reported by the Go runtime. Whilst we could wrap the file in a mutex to allow eager closure, we can rely on the tail routine itself to perform the close, especially after switching to using channel closure instead of a buffered channel. --- follower/follower.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/follower/follower.go b/follower/follower.go index 53bac75..9056f0e 100644 --- a/follower/follower.go +++ b/follower/follower.go @@ -80,9 +80,6 @@ func (t *Follower) Err() error { } func (t *Follower) Close() { - if t.file != nil { - t.file.Close() - } t.closeOnce.Do(func() { close(t.closeCh) }) } From f7b3542df1549b9ce8f1057a1be18f44aae62411 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sat, 11 Jul 2026 16:35:46 -0700 Subject: [PATCH 4/6] Early return on close in Follower sendLine routine This ensures that we react correctly to the follower being closed, instead of potentially blocking on writing to the lines channel. The logic here matches what we do when we notice the close channel being closed later in the same routine. --- follower/follower.go | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/follower/follower.go b/follower/follower.go index 9056f0e..00ee58d 100644 --- a/follower/follower.go +++ b/follower/follower.go @@ -150,7 +150,10 @@ func (t *Follower) follow() error { break } - t.sendLine(s, discarded) + if !t.sendLine(s, discarded) { + t.watcher.Remove(t.filename) + return nil + } } // we're now at EOF, so wait for changes @@ -279,8 +282,13 @@ func (t *Follower) close(err error) { close(t.lines) } -func (t *Follower) sendLine(l []byte, d int) { - t.lines <- Line{l[:len(l)-1], d} +func (t *Follower) sendLine(l []byte, d int) bool { + select { + case t.lines <- Line{l[:len(l)-1], d}: + return true + case <-t.closeCh: + return false + } } func (t *Follower) watchFileEvents(eventChan chan fsnotify.Event, errChan chan error) { From b45d6ced9a731bab7e1303ed718ac93bad9887a2 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sat, 11 Jul 2026 16:53:58 -0700 Subject: [PATCH 5/6] Retry re-opening the file after rename for up to 1 second Previously we re-opened the file exactly once after a rename or remove event, assuming an atomic log rotation operation. However, as is likely in practice, if the rotation program had not yet created the new file, the open failed and the follower exited, permanently stopping the tail. To fix, retry every 50ms for up to 1 second, but only when we actually get a failure due to the file not existing, as was already intended to be implemented and documented in a code comment. --- follower/follower.go | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/follower/follower.go b/follower/follower.go index 00ee58d..4db336f 100644 --- a/follower/follower.go +++ b/follower/follower.go @@ -247,7 +247,16 @@ func (t *Follower) follow() error { func (t *Follower) rewatch() error { t.watcher.Remove(t.filename) - if err := t.reopen(); err != nil { + + // After a rename the new file may not exist yet, retry for up to 1 minute + var err error + for i := 0; i < 20; i++ { + if err = t.reopen(); err == nil || !os.IsNotExist(err) { + break + } + time.Sleep(50 * time.Millisecond) + } + if err != nil { return err } From 82ac8bcb98c1694ff743027ec8d648b21daff2e0 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Sat, 11 Jul 2026 17:09:50 -0700 Subject: [PATCH 6/6] Tests: Avoid data race in assertFollowedLines and simplify it This test method was previously only checking errors that occur immediately when the log tail is set up, and was doing so whilst also actively reading from Lines in a separate Go routine. That is not safe to do due to the lack of a supporting synchronization primitive. Instead, first read all lines, and then check for errors. This depends on the recent TestRenameCreate fix which ensures we don't error out mid-test in some cases (which was previously silently ignored). As reported when running the tests with the "-race" argument. --- follower/follower_test.go | 28 +++++++++++----------------- 1 file changed, 11 insertions(+), 17 deletions(-) diff --git a/follower/follower_test.go b/follower/follower_test.go index 12ae203..be3dbc3 100644 --- a/follower/follower_test.go +++ b/follower/follower_test.go @@ -8,7 +8,6 @@ import ( "os" "path" "runtime" - "sync" "testing" "time" @@ -315,25 +314,20 @@ func writeLines(file *os.File, lines []string) error { func assertFollowedLines(t *testing.T, f *Follower, lines []string) { assert := assert.New(t) - wg := &sync.WaitGroup{} - wg.Add(1) - - go func() { - defer wg.Done() - - i := 0 - for line := range f.Lines() { - assert.Equal(lines[i], line.String()) - i++ - if i == len(lines) { - return - } + i := 0 + for line := range f.Lines() { + assert.Equal(lines[i], line.String()) + i++ + if i == len(lines) { + return } - }() + } + // Lines() closed before all expected lines arrived. Err() is only safe to + // read once Lines() is closed, since the follower goroutine sets the error + // right before closing the channel. if err := f.Err(); err != nil { t.Fatal(err) } - - wg.Wait() + t.Fatalf("lines channel closed early after %d of %d lines", i, len(lines)) }