Skip to content

Commit

Permalink
Add multi-logged integration tests to otelslog (#5329)
Browse files Browse the repository at this point in the history
* Add multi-logged integration tests to otelslog

* Add Go Authors copyright
  • Loading branch information
MrAlias committed Mar 29, 2024
1 parent 336d5b6 commit 59ebbee
Showing 1 changed file with 294 additions and 2 deletions.
296 changes: 294 additions & 2 deletions 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"
Expand All @@ -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())
}
Expand Down Expand Up @@ -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))
Expand All @@ -125,8 +419,6 @@ func TestSLogHandler(t *testing.T) {
t.Fatal(err)
}
})

// TODO: Add multi-logged testing. See #5195.
}

func TestNewHandlerConfiguration(t *testing.T) {
Expand Down

0 comments on commit 59ebbee

Please sign in to comment.