Add multi-logged integration tests to otelslog

bridges/otelslog/handler_test.go

@@ -1,13 +1,21 @@
 // Copyright The OpenTelemetry Authors
 // SPDX-License-Identifier: Apache-2.0
 
+// Copyright 2023 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
 package otelslog
 
 import (
 	"context"
+	"fmt"
 	"log/slog"
+	"reflect"
+	"runtime"
 	"testing"
 	"testing/slogtest"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -18,6 +26,8 @@ import (
 	"go.opentelemetry.io/otel/sdk/instrumentation"
 )
 
+var now = time.Now()
+
 func TestNewLogger(t *testing.T) {
 	assert.IsType(t, &Handler{}, NewLogger().Handler())
 }
@@ -114,7 +124,291 @@ func value2Result(v log.Value) any {
 	return nil
 }
 
+// testCase represents a complete setup/run/check of an slog handler to test.
+// It is based on the testCase from "testing/slogtest" (1.22.1).
+type testCase struct {
+	// Subtest name.
+	name string
+	// If non-empty, explanation explains the violated constraint.
+	explanation string
+	// f executes a single log event using its argument logger.
+	// So that mkdescs.sh can generate the right description,
+	// the body of f must appear on a single line whose first
+	// non-whitespace characters are "l.".
+	f func(*slog.Logger)
+	// If mod is not nil, it is called to modify the Record
+	// generated by the Logger before it is passed to the Handler.
+	mod func(*slog.Record)
+	// checks is a list of checks to run on the result. Each item is a slice of
+	// checks that will be evaluated for the corresponding record emitted.
+	checks [][]check
+}
+
+// copied from slogtest (1.22.1).
+type check func(map[string]any) string
+
+// copied from slogtest (1.22.1).
+func hasKey(key string) check {
+	return func(m map[string]any) string {
+		if _, ok := m[key]; !ok {
+			return fmt.Sprintf("missing key %q", key)
+		}
+		return ""
+	}
+}
+
+// copied from slogtest (1.22.1).
+func missingKey(key string) check {
+	return func(m map[string]any) string {
+		if _, ok := m[key]; ok {
+			return fmt.Sprintf("unexpected key %q", key)
+		}
+		return ""
+	}
+}
+
+// copied from slogtest (1.22.1).
+func hasAttr(key string, wantVal any) check {
+	return func(m map[string]any) string {
+		if s := hasKey(key)(m); s != "" {
+			return s
+		}
+		gotVal := m[key]
+		if !reflect.DeepEqual(gotVal, wantVal) {
+			return fmt.Sprintf("%q: got %#v, want %#v", key, gotVal, wantVal)
+		}
+		return ""
+	}
+}
+
+// copied from slogtest (1.22.1).
+func inGroup(name string, c check) check {
+	return func(m map[string]any) string {
+		v, ok := m[name]
+		if !ok {
+			return fmt.Sprintf("missing group %q", name)
+		}
+		g, ok := v.(map[string]any)
+		if !ok {
+			return fmt.Sprintf("value for group %q is not map[string]any", name)
+		}
+		return c(g)
+	}
+}
+
+// copied from slogtest (1.22.1).
+func withSource(s string) string {
+	_, file, line, ok := runtime.Caller(1)
+	if !ok {
+		panic("runtime.Caller failed")
+	}
+	return fmt.Sprintf("%s (%s:%d)", s, file, line)
+}
+
+// copied from slogtest (1.22.1).
+type wrapper struct {
+	slog.Handler
+	mod func(*slog.Record)
+}
+
+// copied from slogtest (1.22.1).
+func (h *wrapper) Handle(ctx context.Context, r slog.Record) error {
+	h.mod(&r)
+	return h.Handler.Handle(ctx, r)
+}
+
 func TestSLogHandler(t *testing.T) {
+	cases := []testCase{
+		{
+			name:        "Values",
+			explanation: withSource("all slog Values need to be supported"),
+			f: func(l *slog.Logger) {
+				l.Info(
+					"msg",
+					"any", struct{ data int64 }{data: 1},
+					"bool", true,
+					"duration", time.Minute,
+					"float64", 3.14159,
+					"int64", -2,
+					"string", "str",
+					"time", now,
+					"uint64", uint64(3),
+					// KindGroup and KindLogValuer are left for slogtest.TestHandler.
+				)
+			},
+			checks: [][]check{{
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr("any", "{data:1}"),
+				hasAttr("bool", true),
+				hasAttr("duration", int64(time.Minute)),
+				hasAttr("float64", 3.14159),
+				hasAttr("int64", int64(-2)),
+				hasAttr("string", "str"),
+				hasAttr("time", now.UnixNano()),
+				hasAttr("uint64", int64(3)),
+			}},
+		},
+		{
+			name:        "multi-messages",
+			explanation: withSource("this test expects multiple independent messages"),
+			f: func(l *slog.Logger) {
+				l.Info("one")
+				l.Info("two")
+			},
+			checks: [][]check{{
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr(slog.MessageKey, "one"),
+			}, {
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr(slog.MessageKey, "two"),
+			}},
+		},
+		{
+			name:        "multi-attrs",
+			explanation: withSource("attributes from one message do not affect another"),
+			f: func(l *slog.Logger) {
+				l.Info("one", "k", "v")
+				l.Info("two")
+			},
+			checks: [][]check{{
+				hasAttr("k", "v"),
+			}, {
+				missingKey("k"),
+			}},
+		},
+		{
+			name:        "independent-WithAttrs",
+			explanation: withSource("a Handler should only include attributes from its own WithAttr origin"),
+			f: func(l *slog.Logger) {
+				l1 := l.With("a", "b")
+				l2 := l1.With("c", "d")
+				l3 := l1.With("e", "f")
+
+				l3.Info("msg", "k", "v")
+				l2.Info("msg", "k", "v")
+				l1.Info("msg", "k", "v")
+				l.Info("msg", "k", "v")
+			},
+			checks: [][]check{{
+				hasAttr("a", "b"),
+				hasAttr("e", "f"),
+				hasAttr("k", "v"),
+			}, {
+				hasAttr("a", "b"),
+				hasAttr("c", "d"),
+				hasAttr("k", "v"),
+				missingKey("e"),
+			}, {
+				hasAttr("a", "b"),
+				hasAttr("k", "v"),
+				missingKey("c"),
+				missingKey("e"),
+			}, {
+				hasAttr("k", "v"),
+				missingKey("a"),
+				missingKey("c"),
+				missingKey("e"),
+			}},
+		},
+		{
+			name:        "independent-WithGroup",
+			explanation: withSource("a Handler should only include attributes from its own WithGroup origin"),
+			f: func(l *slog.Logger) {
+				l1 := l.WithGroup("G").With("a", "b")
+				l2 := l1.WithGroup("H").With("c", "d")
+				l3 := l1.WithGroup("I").With("e", "f")
+
+				l3.Info("msg", "k", "v")
+				l2.Info("msg", "k", "v")
+				l1.Info("msg", "k", "v")
+				l.Info("msg", "k", "v")
+			},
+			checks: [][]check{{
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr(slog.MessageKey, "msg"),
+				missingKey("a"),
+				missingKey("c"),
+				missingKey("H"),
+				inGroup("G", hasAttr("a", "b")),
+				inGroup("G", inGroup("I", hasAttr("e", "f"))),
+				inGroup("G", inGroup("I", hasAttr("k", "v"))),
+			}, {
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr(slog.MessageKey, "msg"),
+				missingKey("a"),
+				missingKey("c"),
+				inGroup("G", hasAttr("a", "b")),
+				inGroup("G", inGroup("H", hasAttr("c", "d"))),
+				inGroup("G", inGroup("H", hasAttr("k", "v"))),
+			}, {
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr(slog.MessageKey, "msg"),
+				missingKey("a"),
+				missingKey("c"),
+				missingKey("H"),
+				inGroup("G", hasAttr("a", "b")),
+				inGroup("G", hasAttr("k", "v")),
+			}, {
+				hasKey(slog.TimeKey),
+				hasKey(slog.LevelKey),
+				hasAttr("k", "v"),
+				hasAttr(slog.MessageKey, "msg"),
+				missingKey("a"),
+				missingKey("c"),
+				missingKey("G"),
+				missingKey("H"),
+			}},
+		},
+		{
+			name:        "independent-WithGroup.WithAttrs",
+			explanation: withSource("a Handler should only include group attributes from its own WithAttr origin"),
+			f: func(l *slog.Logger) {
+				l = l.WithGroup("G")
+				l.With("a", "b").Info("msg", "k", "v")
+				l.With("c", "d").Info("msg", "k", "v")
+			},
+			checks: [][]check{{
+				inGroup("G", hasAttr("a", "b")),
+				inGroup("G", hasAttr("k", "v")),
+				inGroup("G", missingKey("c")),
+			}, {
+				inGroup("G", hasAttr("c", "d")),
+				inGroup("G", hasAttr("k", "v")),
+				inGroup("G", missingKey("a")),
+			}},
+		},
+	}
+
+	// Based on slogtest.Run.
+	for _, c := range cases {
+		t.Run(c.name, func(t *testing.T) {
+			r := new(recorder)
+			var h slog.Handler = NewHandler(WithLoggerProvider(r))
+			if c.mod != nil {
+				h = &wrapper{h, c.mod}
+			}
+			l := slog.New(h)
+			c.f(l)
+			got := r.Results()
+			if len(got) != len(c.checks) {
+				t.Fatalf("missing record checks: %d records, %d checks", len(got), len(c.checks))
+			}
+			for i, checks := range c.checks {
+				for _, check := range checks {
+					if p := check(got[i]); p != "" {
+						t.Errorf("%s: %s", p, c.explanation)
+					}
+				}
+			}
+		})
+	}
+
 	t.Run("slogtest.TestHandler", func(t *testing.T) {
 		r := new(recorder)
 		h := NewHandler(WithLoggerProvider(r))
@@ -125,8 +419,6 @@ func TestSLogHandler(t *testing.T) {
 			t.Fatal(err)
 		}
 	})
-
-	// TODO: Add multi-logged testing. See #5195.
 }
 
 func TestNewHandlerConfiguration(t *testing.T) {