Fix some debug messages logged on higher log levels.

This commit is contained in:
eleksir
2026-04-18 02:17:39 +03:00
parent 7df8bc1446
commit 8701938c75
2 changed files with 93 additions and 16 deletions

View File

@@ -2,7 +2,6 @@
package log package log
import ( import (
"context"
"fmt" "fmt"
"log" "log"
"log/slog" "log/slog"
@@ -27,11 +26,9 @@ var (
logLevel slog.Level logLevel slog.Level
) )
// slogWriter implements [io.Writer] to redirect standard log to slog.
type ( type (
slogWriter struct { // slogWriter implements [io.Writer] to redirect standard log to slog.
handler slog.Handler slogWriter struct{}
}
) )
// Init sets up logger stuff. // Init sets up logger stuff.
@@ -154,9 +151,9 @@ func Debugf(format string, a ...any) {
slog.Debug(fmt.Sprintf(format, a...)) slog.Debug(fmt.Sprintf(format, a...))
} }
// DebugLogger returns a standard library logger that writes at the configured log level. // DebugLogger returns a standard library logger that writes at debug/warn level.
// This is useful for assigning to http.Server.ErrorLog to route net/http errors // TLS-related errors are logged at debug level, others at warn level.
// through our logger while respecting the configured log level. // Both are filtered by the configured log level: set loglevel to debug to see all messages.
func DebugLogger() *log.Logger { func DebugLogger() *log.Logger {
mu.RLock() mu.RLock()
defer mu.RUnlock() defer mu.RUnlock()
@@ -167,7 +164,9 @@ func DebugLogger() *log.Logger {
handler := slog.NewTextHandler(Log, opts) 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. // 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, "handshake") ||
strings.Contains(msg, "certificate") strings.Contains(msg, "certificate")
level := slog.LevelWarn
if isTLSError { 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 return len(p), nil
} }

View File

@@ -363,7 +363,7 @@ func TestDebugLogger(t *testing.T) {
logFilePath := tmpFile.Name() logFilePath := tmpFile.Name()
tmpFile.Close() tmpFile.Close()
if err := Init("info", logFilePath); err != nil { if err := Init("debug", logFilePath); err != nil {
t.Fatal(err) t.Fatal(err)
} }
defer Close() 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: */ /* vim: setlocal ft=go noet ai ts=4 sw=4 sts=4: */