From 8701938c75a8f6c49718c10af2223593fb13c88d Mon Sep 17 00:00:00 2001 From: eleksir Date: Sat, 18 Apr 2026 02:17:39 +0300 Subject: [PATCH] Fix some debug messages logged on higher log levels. --- internal/log/main.go | 26 ++++++------ internal/log/main_test.go | 83 ++++++++++++++++++++++++++++++++++++++- 2 files changed, 93 insertions(+), 16 deletions(-) diff --git a/internal/log/main.go b/internal/log/main.go index 792f90d..7d58aae 100644 --- a/internal/log/main.go +++ b/internal/log/main.go @@ -2,7 +2,6 @@ package log import ( - "context" "fmt" "log" "log/slog" @@ -27,11 +26,9 @@ var ( logLevel slog.Level ) -// slogWriter implements [io.Writer] to redirect standard log to slog. type ( - slogWriter struct { - handler slog.Handler - } + // slogWriter implements [io.Writer] to redirect standard log to slog. + slogWriter struct{} ) // Init sets up logger stuff. @@ -154,9 +151,9 @@ func Debugf(format string, a ...any) { slog.Debug(fmt.Sprintf(format, a...)) } -// DebugLogger returns a standard library logger that writes at the configured log level. -// This is useful for assigning to http.Server.ErrorLog to route net/http errors -// through our logger while respecting the configured log level. +// DebugLogger returns a standard library logger that writes at debug/warn level. +// TLS-related errors are logged at debug level, others at warn level. +// Both are filtered by the configured log level: set loglevel to debug to see all messages. func DebugLogger() *log.Logger { mu.RLock() defer mu.RUnlock() @@ -167,7 +164,9 @@ func DebugLogger() *log.Logger { handler := slog.NewTextHandler(Log, opts) - return log.New(&slogWriter{handler: handler}, "", 0) + _ = handler // satisfy linter (handler configures level for potential future use). + + return log.New(&slogWriter{}, "", 0) } // Write implements [io.Writer]. It differentiates TLS/SSL errors from other errors. @@ -183,15 +182,12 @@ func (w *slogWriter) Write(p []byte) (int, error) { strings.Contains(msg, "handshake") || strings.Contains(msg, "certificate") - level := slog.LevelWarn if isTLSError { - level = slog.LevelDebug + Debug(msg) + } else { + Warn(msg) } - record := slog.NewRecord(time.Now(), level, msg, 0) - - _ = w.handler.Handle(context.TODO(), record) - return len(p), nil } diff --git a/internal/log/main_test.go b/internal/log/main_test.go index 5a25415..30945f2 100644 --- a/internal/log/main_test.go +++ b/internal/log/main_test.go @@ -363,7 +363,7 @@ func TestDebugLogger(t *testing.T) { logFilePath := tmpFile.Name() tmpFile.Close() - if err := Init("info", logFilePath); err != nil { + if err := Init("debug", logFilePath); err != nil { t.Fatal(err) } defer Close() @@ -385,4 +385,85 @@ func TestDebugLogger(t *testing.T) { } } +// TestDebugLoggerTLS tests that TLS errors are logged at debug level. +func TestDebugLoggerTLS(t *testing.T) { + tmpFile, err := os.CreateTemp(t.TempDir(), "test_log_*.log") + if err != nil { + t.Fatal(err) + } + logFilePath := tmpFile.Name() + tmpFile.Close() + + if err := Init("debug", logFilePath); err != nil { + t.Fatal(err) + } + defer Close() + + logger := DebugLogger() + logger.Print("tls handshake timeout") + + content, err := os.ReadFile(logFilePath) + if err != nil { + t.Fatal(err) + } + + if !strings.Contains(string(content), "tls handshake timeout") { + t.Error("Expected TLS message in log") + } +} + +// TestDebugLoggerNonTLS tests that non-TLS errors are logged at warn level. +func TestDebugLoggerNonTLS(t *testing.T) { + tmpFile, err := os.CreateTemp(t.TempDir(), "test_log_*.log") + if err != nil { + t.Fatal(err) + } + logFilePath := tmpFile.Name() + tmpFile.Close() + + if err := Init("warn", logFilePath); err != nil { + t.Fatal(err) + } + defer Close() + + logger := DebugLogger() + logger.Print("http: connection reset by peer") + + content, err := os.ReadFile(logFilePath) + if err != nil { + t.Fatal(err) + } + + if !strings.Contains(string(content), "http: connection reset by peer") { + t.Error("Expected non-TLS message in log") + } +} + +// TestDebugLoggerLevelFiltering tests that log level filtering works. +func TestDebugLoggerLevelFiltering(t *testing.T) { + tmpFile, err := os.CreateTemp(t.TempDir(), "test_log_*.log") + if err != nil { + t.Fatal(err) + } + logFilePath := tmpFile.Name() + tmpFile.Close() + + if err := Init("info", logFilePath); err != nil { + t.Fatal(err) + } + defer Close() + + logger := DebugLogger() + logger.Print("tls handshake timeout") // TLS error at debug level - should be filtered + + content, err := os.ReadFile(logFilePath) + if err != nil { + t.Fatal(err) + } + + if strings.Contains(string(content), "tls handshake timeout") { + t.Error("Debug-level TLS message should be filtered at info log level") + } +} + /* vim: setlocal ft=go noet ai ts=4 sw=4 sts=4: */