chore: add test to custom logger for Go 1.21+

Author: ccoVeille

logging/custom.go

@@ -54,7 +54,8 @@ func (cl *LoggerWrapper) Errorf(ctx context.Context, format string, v ...any) {
 		legacyLoggerWithLevel.Errorf(ctx, format, v...)
 		return
 	}
-	cl.logger.ErrorContext(cl.printfToStructured(ctx, format, v...))
+	ctx, msg, args := cl.printfToStructured(ctx, format, v...)
+	cl.logger.ErrorContext(ctx, msg, args...)
 }
 
 // Warn is a structured warning level logging method with context and arguments.
@@ -71,7 +72,8 @@ func (cl *LoggerWrapper) Warnf(ctx context.Context, format string, v ...any) {
 		legacyLoggerWithLevel.Warnf(ctx, format, v...)
 		return
 	}
-	cl.logger.WarnContext(cl.printfToStructured(ctx, format, v...))
+	ctx, msg, args := cl.printfToStructured(ctx, format, v...)
+	cl.logger.WarnContext(ctx, msg, args...)
 }
 
 // Info is a structured info level logging method with context and arguments.
@@ -98,15 +100,17 @@ func (cl *LoggerWrapper) Infof(ctx context.Context, format string, v ...any) {
 		return
 	}
 
-	cl.logger.InfoContext(cl.printfToStructured(ctx, format, v...))
+	ctx, msg, args := cl.printfToStructured(ctx, format, v...)
+	cl.logger.InfoContext(ctx, msg, args...)
 }
 
 func (cl *LoggerWrapper) Debugf(ctx context.Context, format string, v ...any) {
 	if cl == nil || cl.logger == nil {
 		legacyLoggerWithLevel.Debugf(ctx, format, v...)
 		return
 	}
-	cl.logger.DebugContext(cl.printfToStructured(ctx, format, v...))
+	ctx, msg, args := cl.printfToStructured(ctx, format, v...)
+	cl.logger.DebugContext(ctx, msg, args...)
 }
 
 func (cl *LoggerWrapper) printfToStructured(ctx context.Context, format string, v ...any) (context.Context, string, []any) {

logging/custom_go121_test.go

@@ -2,9 +2,169 @@
 
 package logging
 
-import "log/slog"
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"log/slog"
+	"testing"
+)
 
 // validation that [slog.Logger] implements [LoggerWithLevelI]
 var _ LoggerWithLevelI = &slog.Logger{}
 
 var _ *LoggerWrapper = NewLoggerWrapper(&slog.Logger{})
+
+func TestLoggerWrapper_slog(t *testing.T) {
+
+	ctx := context.Background()
+
+	t.Run("Debug", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Debug(ctx, "debug message", "foo", "bar")
+
+		checkLog(t, buf, map[string]any{
+			"level": "DEBUG",
+			"msg":   "debug message",
+			"foo":   "bar",
+		})
+	})
+
+	t.Run("Info", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Info(ctx, "info message", "foo", "bar")
+
+		checkLog(t, buf, map[string]any{
+			"level": "INFO",
+			"msg":   "info message",
+			"foo":   "bar",
+		})
+	})
+	t.Run("Warn", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Warn(ctx, "warn message", "foo", "bar")
+
+		checkLog(t, buf, map[string]any{
+			"level": "WARN",
+			"msg":   "warn message",
+			"foo":   "bar",
+		})
+	})
+	t.Run("Error", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Error(ctx, "error message", "foo", "bar")
+
+		checkLog(t, buf, map[string]any{
+			"level": "ERROR",
+			"msg":   "error message",
+			"foo":   "bar",
+		})
+	})
+
+	t.Run("Errorf", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Errorf(ctx, "%d is the answer to %s", 42, "everything")
+
+		checkLog(t, buf, map[string]any{
+			"level": "ERROR",
+			"msg":   "42 is the answer to everything",
+		})
+	})
+
+	t.Run("Infof", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Infof(ctx, "%d is the answer to %s", 42, "everything")
+
+		checkLog(t, buf, map[string]any{
+			"level": "INFO",
+			"msg":   "42 is the answer to everything",
+		})
+	})
+
+	t.Run("Warnf", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Warnf(ctx, "%d is the answer to %s", 42, "everything")
+
+		checkLog(t, buf, map[string]any{
+			"level": "WARN",
+			"msg":   "42 is the answer to everything",
+		})
+	})
+
+	t.Run("Debugf", func(t *testing.T) {
+		wrapped, buf := NewTestLogger(t)
+		wrapped.Debugf(ctx, "%d is the answer to %s", 42, "everything")
+
+		checkLog(t, buf, map[string]any{
+			"level": "DEBUG",
+			"msg":   "42 is the answer to everything",
+		})
+	})
+
+	t.Run("Insufficient loglevel: default", func(t *testing.T) {
+		var buf bytes.Buffer
+		wrapped := NewLoggerWrapper(slog.New(slog.NewJSONHandler(&buf, nil)))
+		wrapped.Debug(ctx, "debug message", "foo", "bar")
+		if buf.Len() != 0 {
+			t.Errorf("expected no log message, got %s", buf.String())
+		}
+	})
+
+	t.Run("Insufficient loglevel: error", func(t *testing.T) {
+		var buf bytes.Buffer
+		wrapped := NewLoggerWrapper(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelError})))
+		wrapped.Debug(ctx, "debug message", "foo", "bar")
+		wrapped.Warn(ctx, "warn message", "foo", "bar")
+		wrapped.Info(ctx, "info message", "foo", "bar")
+		if buf.Len() != 0 {
+			t.Errorf("expected no log message, got %s", buf.String())
+		}
+		wrapped.Error(ctx, "error message", "foo", "bar")
+
+		checkLog(t, &buf, map[string]any{
+			"level": "ERROR",
+			"msg":   "error message",
+			"foo":   "bar",
+		})
+	})
+}
+
+func NewTestLogger(t *testing.T) (*LoggerWrapper, *bytes.Buffer) {
+	var buf bytes.Buffer
+	wrapped := NewLoggerWrapper(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
+	return wrapped, &buf
+}
+
+func checkLog(t *testing.T, buf *bytes.Buffer, attrs map[string]any) {
+	t.Helper()
+
+	res := buf.Bytes()
+
+	var m map[string]any
+	err := json.Unmarshal(res, &m)
+	if err != nil {
+		t.Fatalf("failed to unmarshal log message: %v", err)
+	}
+
+	delete(m, "time") // remove time for testing purposes
+
+	if len(m) != len(attrs) {
+		t.Errorf("expected %d attributes, got %d", len(attrs), len(m))
+	}
+
+	for k, expected := range attrs {
+		v, ok := m[k]
+		if !ok {
+			t.Errorf("expected log to have key %s", k)
+			continue
+		}
+		if v != expected {
+			t.Errorf("expected %s to be %v, got %v", k, expected, v)
+		}
+	}
+
+	if t.Failed() {
+		t.Logf("log message: %s", res)
+		t.Log("time is ignored in comparison")
+	}
+}