From 55fac9670019b8b3be43e8f2662ba4f79f7b7ac2 Mon Sep 17 00:00:00 2001 From: Rogee Date: Sat, 15 Aug 2026 00:04:01 +0800 Subject: [PATCH] H-148: close replaced logger file sinks (#26) Co-authored-by: Rogee --- backend/pkg/logger/logger.go | 49 +++++++++++++++++++------- backend/pkg/logger/logger_test.go | 58 ++++++++++++++++++++++++++----- 2 files changed, 86 insertions(+), 21 deletions(-) diff --git a/backend/pkg/logger/logger.go b/backend/pkg/logger/logger.go index 4b838b9c..edbfe15f 100644 --- a/backend/pkg/logger/logger.go +++ b/backend/pkg/logger/logger.go @@ -8,9 +8,13 @@ import ( "go.uber.org/zap/zapcore" ) -// Logger wraps zap.SugaredLogger for structured logging. -// Corresponds to Chatwoot's Rails Logger but with structured output. -var globalLogger atomic.Pointer[zap.SugaredLogger] +// loggerState keeps a logger and its output handles together for atomic replacement. +type loggerState struct { + logger *zap.SugaredLogger + outputs []*os.File +} + +var globalLogger atomic.Pointer[loggerState] // Config for logger initialization type Config struct { @@ -46,6 +50,7 @@ func Init(cfg Config) error { } errorWriter, err := getOutput(cfg.ErrorOutput) if err != nil { + closeOutput(outputWriter) return err } @@ -65,30 +70,50 @@ func Init(cfg Config) error { combinedCore := zapcore.NewTee(core, errorCore) zapLogger := zap.New(combinedCore, zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel)) - globalLogger.Store(zapLogger.Sugar()) + old := globalLogger.Swap(&loggerState{ + logger: zapLogger.Sugar(), + outputs: []*os.File{outputWriter, errorWriter}, + }) + closeState(old) return nil } // L returns the global sugared logger func L() *zap.SugaredLogger { - if logger := globalLogger.Load(); logger != nil { - return logger + if state := globalLogger.Load(); state != nil { + return state.logger } // Fallback: if Init wasn't called, use a default logger. zapLogger, _ := zap.NewProduction() - logger := zapLogger.Sugar() - if globalLogger.CompareAndSwap(nil, logger) { - return logger + state := &loggerState{logger: zapLogger.Sugar()} + if globalLogger.CompareAndSwap(nil, state) { + return state.logger } - return globalLogger.Load() + return globalLogger.Load().logger } // Sync flushes any buffered log entries. Should be called before program exit. func Sync() { - if logger := globalLogger.Load(); logger != nil { - _ = logger.Sync() + if state := globalLogger.Load(); state != nil { + _ = state.logger.Sync() + } +} + +func closeState(state *loggerState) { + if state == nil { + return + } + _ = state.logger.Sync() + for _, output := range state.outputs { + closeOutput(output) + } +} + +func closeOutput(file *os.File) { + if file != nil && file != os.Stdout && file != os.Stderr { + _ = file.Close() } } diff --git a/backend/pkg/logger/logger_test.go b/backend/pkg/logger/logger_test.go index 8df868ba..aa3d65df 100644 --- a/backend/pkg/logger/logger_test.go +++ b/backend/pkg/logger/logger_test.go @@ -3,12 +3,17 @@ package logger import ( "os" "path/filepath" + "sync" "testing" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) +func resetLogger() { + closeState(globalLogger.Swap(nil)) +} + func TestParseLevel_AllLevels(t *testing.T) { tests := []struct { input string @@ -81,7 +86,7 @@ func TestInit_JSONFormat(t *testing.T) { } err := Init(cfg) assert.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() // globalLogger should be set require.NotNil(t, globalLogger.Load()) @@ -96,7 +101,7 @@ func TestInit_ConsoleFormat(t *testing.T) { } err := Init(cfg) assert.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() require.NotNil(t, globalLogger.Load()) } @@ -114,7 +119,7 @@ func TestInit_FileOutput(t *testing.T) { } err := Init(cfg) assert.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() require.NotNil(t, globalLogger.Load()) @@ -127,6 +132,40 @@ func TestInit_FileOutput(t *testing.T) { assert.NoError(t, statErr) } +func TestInit_ReplacesFileOutputsWithoutLeakingDescriptors(t *testing.T) { + const fdDir = "/proc/self/fd" + resetLogger() + defer resetLogger() + + before, err := os.ReadDir(fdDir) + if err != nil { + t.Skip("open file descriptor inspection is unavailable") + } + + dir := t.TempDir() + cfg := Config{ + Level: "info", + Format: "json", + Output: filepath.Join(dir, "app.log"), + ErrorOutput: filepath.Join(dir, "err.log"), + } + var wg sync.WaitGroup + for range 20 { + wg.Add(1) + go func() { + defer wg.Done() + _ = L() + Sync() + }() + require.NoError(t, Init(cfg)) + } + wg.Wait() + + after, err := os.ReadDir(fdDir) + require.NoError(t, err) + require.LessOrEqual(t, len(after), len(before)+2) +} + func TestInit_InvalidLevel(t *testing.T) { // parseLevel never returns an error, so Init should succeed even with an // unknown level (defaults to info). This test verifies that behavior. @@ -138,7 +177,7 @@ func TestInit_InvalidLevel(t *testing.T) { } err := Init(cfg) assert.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() } func TestInit_InvalidOutput(t *testing.T) { @@ -165,7 +204,8 @@ func TestInit_InvalidErrorOutput(t *testing.T) { func TestL_WithoutInit(t *testing.T) { // Reset globalLogger to nil to test the fallback path - globalLogger.Store(nil) + resetLogger() + defer resetLogger() l := L() assert.NotNil(t, l) // Should be a usable sugared logger @@ -181,7 +221,7 @@ func TestL_AfterInit(t *testing.T) { } err := Init(cfg) require.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() l := L() assert.NotNil(t, l) @@ -196,14 +236,14 @@ func TestSync_WithLogger(t *testing.T) { } err := Init(cfg) require.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() L().Info("message before sync") Sync() } func TestSync_WithoutLogger(t *testing.T) { - globalLogger.Store(nil) + resetLogger() // Should not panic Sync() } @@ -217,7 +257,7 @@ func TestL_LogsAtVariousLevels(t *testing.T) { } err := Init(cfg) require.NoError(t, err) - defer globalLogger.Store(nil) + defer resetLogger() l := L() l.Debug("debug message")