From a20306e6a14a5cf199d03548d749c08092002e7a Mon Sep 17 00:00:00 2001 From: Ciprian Hacman Date: Sat, 11 Jul 2026 10:24:03 +0300 Subject: [PATCH] fix(logwatchers/kmsg): don't close the old parser twice when Stop() interrupts a restart The restart path closes the failed parser before retrying. If stopping is signaled during the retry wait, watchLoop's deferred cleanup closed the same parser again, logging a spurious 'file already closed' error at shutdown. Clear the reference after closing and nil-check the defer. --- .../logwatchers/kmsg/log_watcher_linux.go | 11 ++-- .../kmsg/log_watcher_linux_test.go | 53 +++++++++++++++++++ 2 files changed, 61 insertions(+), 3 deletions(-) diff --git a/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux.go b/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux.go index fa6d8cf2..c82da381 100644 --- a/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux.go +++ b/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux.go @@ -94,8 +94,11 @@ func (k *kernelLogWatcher) Stop() { func (k *kernelLogWatcher) watchLoop() { kmsgs := k.kmsgParser.Parse() defer func() { - if err := k.kmsgParser.Close(); err != nil { - klog.Errorf("Failed to close kmsg parser: %v", err) + // kmsgParser is nil when stopping interrupted a restart. + if k.kmsgParser != nil { + if err := k.kmsgParser.Close(); err != nil { + klog.Errorf("Failed to close kmsg parser: %v", err) + } } close(k.logCh) k.tomb.Done() @@ -110,10 +113,12 @@ func (k *kernelLogWatcher) watchLoop() { if !ok { klog.Error("Kmsg channel closed, attempting to restart kmsg parser") - // Close the old parser + // Close the old parser and clear the reference so the + // deferred cleanup doesn't close it a second time. if err := k.kmsgParser.Close(); err != nil { klog.Errorf("Failed to close kmsg parser: %v", err) } + k.kmsgParser = nil // Try to restart. retryCreateParser() waits between attempts. var restarted bool diff --git a/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux_test.go b/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux_test.go index 3767b986..25c181c1 100644 --- a/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux_test.go +++ b/pkg/systemlogmonitor/logwatchers/kmsg/log_watcher_linux_test.go @@ -468,6 +468,59 @@ func TestWatcherRateLimitsRestarts(t *testing.T) { } } +// TestStopDuringRestartClosesOldParserOnce verifies that when Stop() arrives +// while the watcher is in the restart path, the already-closed old parser is +// not closed a second time by watchLoop's deferred cleanup. +func TestStopDuringRestartClosesOldParserOnce(t *testing.T) { + now := time.Now() + + // Closing the channel after sending drives watchLoop into the restart path. + mock := &mockKmsgParser{ + kmsgs: []kmsgparser.Message{{Message: "msg", Timestamp: now}}, + closeAfterSend: true, + } + + factoryCalled := make(chan struct{}, 1) + w := &kernelLogWatcher{ + cfg: types.WatcherConfig{}, + startTime: now.Add(-time.Minute), + tomb: tomb.NewTomb(), + logCh: make(chan *logtypes.Log, 100), + kmsgParser: mock, + newParser: func() (kmsgparser.Parser, error) { + select { + case factoryCalled <- struct{}{}: + default: + } + // Keep the watcher in the retry loop until Stop() is called. + return nil, fmt.Errorf("kmsg unavailable") + }, + } + + logCh, err := w.Watch() + assert.NoError(t, err) + <-logCh + + // Wait until watchLoop has entered the restart path. + select { + case <-factoryCalled: + case <-time.After(time.Second): + t.Fatal("timeout waiting for restart attempt") + } + + w.Stop() + + select { + case _, ok := <-logCh: + assert.False(t, ok, "log channel should be closed after Stop()") + case <-time.After(time.Second): + t.Fatal("timeout waiting for log channel to close after Stop()") + } + + assert.Equal(t, 1, mock.CloseCallCount(), + "old parser must be closed exactly once, not again by watchLoop's defer") +} + // TestStopDoesNotDeadlockWhenLogChannelFull verifies that Stop() returns even // when logCh is full and nobody is draining it. func TestStopDoesNotDeadlockWhenLogChannelFull(t *testing.T) {