From e52793efdd909ca7cf1cb5e4a91b82a7d860cd08 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 22:45:41 +0100 Subject: [PATCH 01/40] log/logtest: Redesign --- log/logtest/assertions.go | 74 ------------- log/logtest/assertions_test.go | 34 ------ log/logtest/factory.go | 38 ------- log/logtest/factory_test.go | 70 ------------ log/logtest/recorder.go | 187 ++++++++++++++++++++++++--------- log/logtest/recorder_test.go | 115 +++++++------------- 6 files changed, 175 insertions(+), 343 deletions(-) delete mode 100644 log/logtest/assertions.go delete mode 100644 log/logtest/assertions_test.go delete mode 100644 log/logtest/factory.go delete mode 100644 log/logtest/factory_test.go diff --git a/log/logtest/assertions.go b/log/logtest/assertions.go deleted file mode 100644 index 479cc3b0876..00000000000 --- a/log/logtest/assertions.go +++ /dev/null @@ -1,74 +0,0 @@ -// Copyright The OpenTelemetry Authors -// SPDX-License-Identifier: Apache-2.0 - -package logtest // import "go.opentelemetry.io/otel/log/logtest" - -import ( - "slices" - "testing" - - "go.opentelemetry.io/otel/log" -) - -// AssertRecordEqual compares two log records, and fails the test if they are -// not equal. -func AssertRecordEqual(t testing.TB, want, got log.Record) bool { - t.Helper() - - if want.EventName() != got.EventName() { - t.Errorf("EventName value is not equal:\nwant: %v\ngot: %v", want.EventName(), got.EventName()) - return false - } - if !want.Timestamp().Equal(got.Timestamp()) { - t.Errorf("Timestamp value is not equal:\nwant: %v\ngot: %v", want.Timestamp(), got.Timestamp()) - return false - } - if !want.ObservedTimestamp().Equal(got.ObservedTimestamp()) { - t.Errorf("ObservedTimestamp value is not equal:\nwant: %v\ngot: %v", want.ObservedTimestamp(), got.ObservedTimestamp()) - return false - } - if want.Severity() != got.Severity() { - t.Errorf("Severity value is not equal:\nwant: %v\ngot: %v", want.Severity(), got.Severity()) - return false - } - if want.SeverityText() != got.SeverityText() { - t.Errorf("SeverityText value is not equal:\nwant: %v\ngot: %v", want.SeverityText(), got.SeverityText()) - return false - } - if !assertBody(t, want.Body(), got) { - return false - } - - var attrs []log.KeyValue - want.WalkAttributes(func(kv log.KeyValue) bool { - attrs = append(attrs, kv) - return true - }) - return assertAttributes(t, attrs, got) -} - -func assertBody(t testing.TB, want log.Value, r log.Record) bool { - t.Helper() - got := r.Body() - if !got.Equal(want) { - t.Errorf("Body value is not equal:\nwant: %v\ngot: %v", want, got) - return false - } - - return true -} - -func assertAttributes(t testing.TB, want []log.KeyValue, r log.Record) bool { - t.Helper() - var got []log.KeyValue - r.WalkAttributes(func(kv log.KeyValue) bool { - got = append(got, kv) - return true - }) - if !slices.EqualFunc(want, got, log.KeyValue.Equal) { - t.Errorf("Attributes are not equal:\nwant: %v\ngot: %v", want, got) - return false - } - - return true -} diff --git a/log/logtest/assertions_test.go b/log/logtest/assertions_test.go deleted file mode 100644 index 04d62d15d35..00000000000 --- a/log/logtest/assertions_test.go +++ /dev/null @@ -1,34 +0,0 @@ -// Copyright The OpenTelemetry Authors -// SPDX-License-Identifier: Apache-2.0 - -package logtest - -import ( - "testing" - "time" - - "go.opentelemetry.io/otel/log" -) - -func TestAssertRecord(t *testing.T) { - r1 := log.Record{} - r2 := log.Record{} - AssertRecordEqual(t, r1, r2) - - now := time.Now() - r1.SetEventName("my_event") - r2.SetEventName("my_event") - r1.SetTimestamp(now) - r2.SetTimestamp(now) - r1.SetObservedTimestamp(now) - r2.SetObservedTimestamp(now) - r1.SetSeverity(log.SeverityTrace1) - r2.SetSeverity(log.SeverityTrace1) - r1.SetSeverityText("trace") - r2.SetSeverityText("trace") - r1.SetBody(log.StringValue("log body")) - r2.SetBody(log.StringValue("log body")) - r1.AddAttributes(log.Bool("attr", true)) - r2.AddAttributes(log.Bool("attr", true)) - AssertRecordEqual(t, r1, r2) -} diff --git a/log/logtest/factory.go b/log/logtest/factory.go deleted file mode 100644 index 0c3b389c3dc..00000000000 --- a/log/logtest/factory.go +++ /dev/null @@ -1,38 +0,0 @@ -// Copyright The OpenTelemetry Authors -// SPDX-License-Identifier: Apache-2.0 - -package logtest // import "go.opentelemetry.io/otel/log/logtest" - -import ( - "time" - - "go.opentelemetry.io/otel/log" -) - -// RecordFactory is used to facilitate unit testing bridge implementations that -// make use of a [go.opentelemetry.io/otel/log.Record] -// -// Do not use RecordFactory to create records in production code. -type RecordFactory struct { - EventName string - Timestamp time.Time - ObservedTimestamp time.Time - Severity log.Severity - SeverityText string - Body log.Value - Attributes []log.KeyValue -} - -// NewRecord returns a log record. -func (b RecordFactory) NewRecord() log.Record { - var record log.Record - record.SetEventName(b.EventName) - record.SetTimestamp(b.Timestamp) - record.SetObservedTimestamp(b.ObservedTimestamp) - record.SetSeverity(b.Severity) - record.SetSeverityText(b.SeverityText) - record.SetBody(b.Body) - record.AddAttributes(b.Attributes...) - - return record -} diff --git a/log/logtest/factory_test.go b/log/logtest/factory_test.go deleted file mode 100644 index 084c31bc22f..00000000000 --- a/log/logtest/factory_test.go +++ /dev/null @@ -1,70 +0,0 @@ -// Copyright The OpenTelemetry Authors -// SPDX-License-Identifier: Apache-2.0 - -package logtest - -import ( - "testing" - "time" - - "github.com/stretchr/testify/assert" - - "go.opentelemetry.io/otel/log" -) - -func TestRecordFactory(t *testing.T) { - now := time.Now() - observed := now.Add(time.Second) - evnt := "my_event" - severity := log.SeverityDebug - severityText := "DBG" - body := log.StringValue("Message") - attrs := []log.KeyValue{ - log.Int("int", 1), - log.String("str", "foo"), - log.Float64("flt", 3.14), - } - - got := RecordFactory{ - EventName: evnt, - Timestamp: now, - ObservedTimestamp: observed, - Severity: severity, - SeverityText: severityText, - Body: body, - Attributes: attrs, - }.NewRecord() - - assert.Equal(t, evnt, got.EventName()) - assert.Equal(t, now, got.Timestamp()) - assert.Equal(t, observed, got.ObservedTimestamp()) - assert.Equal(t, severity, got.Severity()) - assert.Equal(t, severityText, got.SeverityText()) - assertBody(t, body, got) - assertAttributes(t, attrs, got) -} - -func TestRecordFactoryMultiple(t *testing.T) { - now := time.Now() - attrs := []log.KeyValue{ - log.Int("int", 1), - log.String("str", "foo"), - log.Float64("flt", 3.14), - } - - f := RecordFactory{ - Timestamp: now, - Attributes: attrs, - } - - record1 := f.NewRecord() - f.Attributes = append(f.Attributes, log.Bool("added", true)) - - record2 := f.NewRecord() - assert.Equal(t, now, record2.Timestamp()) - assertAttributes(t, append(attrs, log.Bool("added", true)), record2) - - // Previously returned record is unharmed by the builder changes. - assert.Equal(t, now, record1.Timestamp()) - assertAttributes(t, attrs, record1) -} diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index fd986c9afc4..52b4bc7d016 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -4,14 +4,33 @@ package logtest // import "go.opentelemetry.io/otel/log/logtest" import ( + "cmp" "context" + "maps" + "slices" "sync" + "time" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/embedded" ) +// Recorder stores all received log records in-memory. +// Recorder implements [log.LoggerProvider]. +type Recorder struct { + embedded.LoggerProvider + + mu sync.Mutex + loggers map[Scope]*logger + + // enabledFn decides whether the recorder should enable logging of a record or not + enabledFn enabledFn +} + +// Compile-time check Recorder implements log.LoggerProvider. +var _ log.LoggerProvider = (*Recorder)(nil) + type enabledFn func(context.Context, log.EnabledParameters) bool var defaultEnabledFunc = func(context.Context, log.EnabledParameters) bool { @@ -55,13 +74,25 @@ func NewRecorder(options ...Option) *Recorder { cfg := newConfig(options) return &Recorder{ + loggers: make(map[Scope]*logger), enabledFn: cfg.enabledFn, } } -// ScopeRecords represents the records for a single instrumentation scope. -type ScopeRecords struct { - // Name is the name of the instrumentation scope. +// Result represents the recordered log record. +type Result map[Scope][]*Record + +// Equal returns if a is equal to b. +func (a Result) Equal(b Result) bool { + return maps.EqualFunc(a, b, func(x, y []*Record) bool { + return slices.EqualFunc(x, y, func(a, b *Record) bool { return a.Equal(b) }) + }) +} + +// Scope represents the instrumentation scope. +type Scope struct { + // Name is the name of the instrumentation scope. This should be the + // Go package name of that scope. Name string // Version is the version of the instrumentation scope. Version string @@ -69,73 +100,114 @@ type ScopeRecords struct { SchemaURL string // Attributes of the telemetry emitted by the scope. Attributes attribute.Set - - // Records are the log records, and their associated context this - // instrumentation scope recorded. - Records []EmittedRecord } -// EmittedRecord holds a log record the instrumentation received, alongside its -// context. -type EmittedRecord struct { - log.Record - - ctx context.Context +// Record represents the record alongside its context. +type Record struct { + Context context.Context + EventName string + Timestamp time.Time + ObservedTimestamp time.Time + Severity log.Severity + SeverityText string + Body log.Value + Attributes []log.KeyValue } -// Context provides the context emitted with the record. -func (rwc EmittedRecord) Context() context.Context { - return rwc.ctx +// Equal returns if a is equal to b. +func (a *Record) Equal(b *Record) bool { + if a.Context != b.Context { + return false + } + if a.EventName != b.EventName { + return false + } + if a.Timestamp != b.Timestamp { //nolint:revive // We want to indeed compare using !=. + return false + } + if a.ObservedTimestamp != b.ObservedTimestamp { //nolint:revive // We want to indeed compare using !=. + return false + } + if a.Severity != b.Severity { + return false + } + if a.SeverityText != b.SeverityText { + return false + } + if !a.Body.Equal(b.Body) { + return false + } + aAttrs := sortKVs(a.Attributes) + bAttrs := sortKVs(b.Attributes) + if !slices.EqualFunc(aAttrs, bAttrs, log.KeyValue.Equal) { //nolint:gosimple // We want to use the same pattern. + return false + } + return true } -// Recorder is a recorder that stores all received log records -// in-memory. -type Recorder struct { - embedded.LoggerProvider - - mu sync.Mutex - loggers []*logger +// Clone returns a deep copy. +func (a *Record) Clone() *Record { + b := *a + attrs := make([]log.KeyValue, len(a.Attributes)) + copy(attrs, a.Attributes) + b.Attributes = attrs + return &b +} - // enabledFn decides whether the recorder should enable logging of a record or not - enabledFn enabledFn +func sortKVs(kvs []log.KeyValue) []log.KeyValue { + s := make([]log.KeyValue, len(kvs)) + copy(s, kvs) + slices.SortFunc(s, func(a, b log.KeyValue) int { + return cmp.Compare(a.Key, b.Key) + }) + return s } // Logger returns a copy of Recorder as a [log.Logger] with the provided scope // information. func (r *Recorder) Logger(name string, opts ...log.LoggerOption) log.Logger { cfg := log.NewLoggerConfig(opts...) - - nl := &logger{ - scopeRecord: &ScopeRecords{ - Name: name, - Version: cfg.InstrumentationVersion(), - SchemaURL: cfg.SchemaURL(), - Attributes: cfg.InstrumentationAttributes(), - }, - enabledFn: r.enabledFn, + scope := Scope{ + Name: name, + Version: cfg.InstrumentationVersion(), + SchemaURL: cfg.SchemaURL(), + Attributes: cfg.InstrumentationAttributes(), } - r.addChildLogger(nl) - - return nl -} -func (r *Recorder) addChildLogger(nl *logger) { r.mu.Lock() defer r.mu.Unlock() - r.loggers = append(r.loggers, nl) + if r.loggers == nil { + r.loggers = make(map[Scope]*logger) + } + + l, ok := r.loggers[scope] + if ok { + return l + } + l = &logger{ + enabledFn: r.enabledFn, + } + r.loggers[scope] = l + return l } // Result returns the current in-memory recorder log records. -func (r *Recorder) Result() []*ScopeRecords { +func (r *Recorder) Result() Result { r.mu.Lock() defer r.mu.Unlock() - ret := []*ScopeRecords{} - for _, l := range r.loggers { - ret = append(ret, l.scopeRecord) + res := make(Result, len(r.loggers)) + for s, l := range r.loggers { + l.mu.Lock() + recs := make([]*Record, len(l.records)) + for i, r := range l.records { + recs[i] = r.Clone() + } + res[s] = recs + l.mu.Unlock() } - return ret + return res } // Reset clears the in-memory log records for all loggers. @@ -151,8 +223,8 @@ func (r *Recorder) Reset() { type logger struct { embedded.Logger - mu sync.Mutex - scopeRecord *ScopeRecords + mu sync.Mutex + records []*Record // enabledFn decides whether the recorder should enable logging of a record or not. enabledFn enabledFn @@ -172,7 +244,24 @@ func (l *logger) Emit(ctx context.Context, record log.Record) { l.mu.Lock() defer l.mu.Unlock() - l.scopeRecord.Records = append(l.scopeRecord.Records, EmittedRecord{record, ctx}) + attrs := make([]log.KeyValue, 0, record.AttributesLen()) + record.WalkAttributes(func(kv log.KeyValue) bool { + attrs = append(attrs, kv) + return true + }) + + r := &Record{ + Context: ctx, + EventName: record.EventName(), + Timestamp: record.Timestamp(), + ObservedTimestamp: record.ObservedTimestamp(), + Severity: record.Severity(), + SeverityText: record.SeverityText(), + Body: record.Body(), + Attributes: attrs, + } + + l.records = append(l.records, r) } // Reset clears the in-memory log records. @@ -180,5 +269,5 @@ func (l *logger) Reset() { l.mu.Lock() defer l.mu.Unlock() - l.scopeRecord.Records = nil + l.records = nil } diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 28d814528e2..28956cc4abd 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -7,60 +7,13 @@ import ( "context" "sync" "testing" + "time" "github.com/stretchr/testify/assert" - "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/log" ) -func TestRecorderLogger(t *testing.T) { - for _, tt := range []struct { - name string - options []Option - - loggerName string - loggerOptions []log.LoggerOption - - wantLogger log.Logger - }{ - { - name: "provides a default logger", - - wantLogger: &logger{ - scopeRecord: &ScopeRecords{}, - }, - }, - { - name: "provides a logger with a configured scope", - - loggerName: "test", - loggerOptions: []log.LoggerOption{ - log.WithInstrumentationVersion("logtest v42"), - log.WithSchemaURL("https://example.com"), - log.WithInstrumentationAttributes(attribute.String("foo", "bar")), - }, - - wantLogger: &logger{ - scopeRecord: &ScopeRecords{ - Name: "test", - Version: "logtest v42", - SchemaURL: "https://example.com", - Attributes: attribute.NewSet(attribute.String("foo", "bar")), - }, - }, - }, - } { - t.Run(tt.name, func(t *testing.T) { - l := NewRecorder(tt.options...).Logger(tt.loggerName, tt.loggerOptions...) - // unset enabledFn to allow comparison - l.(*logger).enabledFn = nil - - assert.Equal(t, tt.wantLogger, l) - }) - } -} - func TestRecorderLoggerCreatesNewStruct(t *testing.T) { r := &Recorder{} assert.NotEqual(t, r, r.Logger("test")) @@ -103,40 +56,46 @@ func TestLoggerEnabledFnUnset(t *testing.T) { } func TestRecorderEmitAndReset(t *testing.T) { - r := NewRecorder() - l := r.Logger("test") - assert.Empty(t, r.Result()[0].Records) + rec := NewRecorder() - r1 := log.Record{} - r1.SetSeverity(log.SeverityInfo) + // Emit a record. + l := rec.Logger(t.Name()) ctx := context.Background() + r := log.Record{} + r.SetSeverity(log.SeverityInfo) + r.SetTimestamp(time.Now()) + r.SetBody(log.StringValue("Hello there")) + l.Emit(ctx, r) + + got := rec.Result() + // Ignore Timestamp. + for _, v := range got { + for _, r := range v { + r.Timestamp = time.Time{} + } + } + want := Result{ + Scope{Name: t.Name()}: []*Record{ + { + Context: ctx, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + }, + }, + } + if !got.Equal(want) { + t.Errorf("Recorded records mismatch\ngot:\n%#v\nwant:\n%#v", got, want) + } - l.Emit(ctx, r1) - assert.Equal(t, []EmittedRecord{ - {r1, ctx}, - }, r.Result()[0].Records) - - nl := r.Logger("test") - assert.Empty(t, r.Result()[1].Records) - - r2 := log.Record{} - r2.SetSeverity(log.SeverityError) - // We want a non-background context here so it's different from `ctx`. - ctx2, cancel := context.WithCancel(ctx) - defer cancel() - - nl.Emit(ctx2, r2) - assert.Len(t, r.Result()[0].Records, 1) - AssertRecordEqual(t, r.Result()[0].Records[0].Record, r1) - assert.Equal(t, r.Result()[0].Records[0].Context(), ctx) - - assert.Len(t, r.Result()[1].Records, 1) - AssertRecordEqual(t, r.Result()[1].Records[0].Record, r2) - assert.Equal(t, r.Result()[1].Records[0].Context(), ctx2) + rec.Reset() - r.Reset() - assert.Empty(t, r.Result()[0].Records) - assert.Empty(t, r.Result()[1].Records) + got = rec.Result() + want = Result{ + Scope{Name: t.Name()}: nil, + } + if !got.Equal(want) { + t.Errorf("Records should be cleared\ngot:\n%#v\nwant:\n%#v", got, want) + } } func TestRecorderConcurrentSafe(t *testing.T) { From 17d92c9e1745a0f966fa081e886df6ba0b709cf3 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 22:48:14 +0100 Subject: [PATCH 02/40] Use Time.Equal --- log/logtest/recorder.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index 52b4bc7d016..ddc1d397d4c 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -122,10 +122,10 @@ func (a *Record) Equal(b *Record) bool { if a.EventName != b.EventName { return false } - if a.Timestamp != b.Timestamp { //nolint:revive // We want to indeed compare using !=. + if !a.Timestamp.Equal(b.Timestamp) { return false } - if a.ObservedTimestamp != b.ObservedTimestamp { //nolint:revive // We want to indeed compare using !=. + if !a.ObservedTimestamp.Equal(b.ObservedTimestamp) { return false } if a.Severity != b.Severity { From 030f8a78d51893eabfdd69ffad0c4c1cd67c41bd Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:08:30 +0100 Subject: [PATCH 03/40] Refactor --- log/logtest/recorder.go | 16 ++++++++-------- log/logtest/recorder_test.go | 7 ++++--- 2 files changed, 12 insertions(+), 11 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index ddc1d397d4c..d8ec9713fc3 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -80,12 +80,12 @@ func NewRecorder(options ...Option) *Recorder { } // Result represents the recordered log record. -type Result map[Scope][]*Record +type Result map[Scope][]Record // Equal returns if a is equal to b. func (a Result) Equal(b Result) bool { - return maps.EqualFunc(a, b, func(x, y []*Record) bool { - return slices.EqualFunc(x, y, func(a, b *Record) bool { return a.Equal(b) }) + return maps.EqualFunc(a, b, func(x, y []Record) bool { + return slices.EqualFunc(x, y, func(a, b Record) bool { return a.Equal(b) }) }) } @@ -115,7 +115,7 @@ type Record struct { } // Equal returns if a is equal to b. -func (a *Record) Equal(b *Record) bool { +func (a Record) Equal(b Record) bool { if a.Context != b.Context { return false } @@ -146,12 +146,12 @@ func (a *Record) Equal(b *Record) bool { } // Clone returns a deep copy. -func (a *Record) Clone() *Record { - b := *a +func (a Record) Clone() Record { + b := a attrs := make([]log.KeyValue, len(a.Attributes)) copy(attrs, a.Attributes) b.Attributes = attrs - return &b + return b } func sortKVs(kvs []log.KeyValue) []log.KeyValue { @@ -200,7 +200,7 @@ func (r *Recorder) Result() Result { res := make(Result, len(r.loggers)) for s, l := range r.loggers { l.mu.Lock() - recs := make([]*Record, len(l.records)) + recs := make([]Record, len(l.records)) for i, r := range l.records { recs[i] = r.Clone() } diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 28956cc4abd..7bc4253bdfd 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -70,12 +70,13 @@ func TestRecorderEmitAndReset(t *testing.T) { got := rec.Result() // Ignore Timestamp. for _, v := range got { - for _, r := range v { + for i, r := range v { r.Timestamp = time.Time{} + v[i] = r } } want := Result{ - Scope{Name: t.Name()}: []*Record{ + Scope{Name: t.Name()}: []Record{ { Context: ctx, Severity: log.SeverityInfo, @@ -84,7 +85,7 @@ func TestRecorderEmitAndReset(t *testing.T) { }, } if !got.Equal(want) { - t.Errorf("Recorded records mismatch\ngot:\n%#v\nwant:\n%#v", got, want) + t.Errorf("Recorded records mismatch\ngot:\n%+v\nwant:\n%+v", got, want) } rec.Reset() From bf915ff6fb4e6dcc81616163183d28a265f10de0 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:09:22 +0100 Subject: [PATCH 04/40] Refactor --- log/logtest/recorder_test.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 7bc4253bdfd..cda8399abc3 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -69,10 +69,10 @@ func TestRecorderEmitAndReset(t *testing.T) { got := rec.Result() // Ignore Timestamp. - for _, v := range got { - for i, r := range v { + for _, recs := range got { + for i, r := range recs { r.Timestamp = time.Time{} - v[i] = r + recs[i] = r } } want := Result{ From c77a09f44b2d083aacfa71e1c1029978a75144b6 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:09:44 +0100 Subject: [PATCH 05/40] Better printing --- log/logtest/recorder_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index cda8399abc3..ecc2d549415 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -95,7 +95,7 @@ func TestRecorderEmitAndReset(t *testing.T) { Scope{Name: t.Name()}: nil, } if !got.Equal(want) { - t.Errorf("Records should be cleared\ngot:\n%#v\nwant:\n%#v", got, want) + t.Errorf("Records should be cleared\ngot:\n%+v\nwant:\n%+v", got, want) } } From a470236346861921fd765a030a418a61768e74b3 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:14:12 +0100 Subject: [PATCH 06/40] Fix grammar --- log/logtest/recorder.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index d8ec9713fc3..a1277390867 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -79,7 +79,7 @@ func NewRecorder(options ...Option) *Recorder { } } -// Result represents the recordered log record. +// Result represents the recordered log records. type Result map[Scope][]Record // Equal returns if a is equal to b. From d8c692dcb489ef17c7a2c71923f42495bac7278b Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:27:14 +0100 Subject: [PATCH 07/40] Add examples --- log/logtest/example_test.go | 70 +++++++++++++++++++++++++++++++++++++ 1 file changed, 70 insertions(+) create mode 100644 log/logtest/example_test.go diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go new file mode 100644 index 00000000000..459b020b529 --- /dev/null +++ b/log/logtest/example_test.go @@ -0,0 +1,70 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package logtest_test + +import ( + "context" + "fmt" + "time" + + "go.opentelemetry.io/otel/log" + "go.opentelemetry.io/otel/log/logtest" +) + +func Example() { + // Create a recorder. + rec := logtest.NewRecorder() + + // Emit a record). + l := rec.Logger("Example") + ctx := context.Background() + r := log.Record{} + r.SetTimestamp(time.Now()) + r.SetSeverity(log.SeverityInfo) + r.SetBody(log.StringValue("Hello there")) + l.Emit(ctx, r) + + // Check what was recorded. + got := rec.Result() + for _, records := range got { + for _, record := range records { + fmt.Printf("%s: %s\n", record.Severity, record.Body) + } + } + + // Output: + // INFO: Hello there +} + +func Example_ignoreTimestamp() { + // Create a recorder. + rec := logtest.NewRecorder() + + // Emit a record). + l := rec.Logger("Example") + ctx := context.Background() + r := log.Record{} + r.SetTimestamp(time.Now()) + r.SetSeverity(log.SeverityInfo) + r.SetBody(log.StringValue("Hello there")) + l.Emit(ctx, r) + + // Ignore Timestamp. + got := rec.Result() + for _, recs := range got { + for i, r := range recs { + r.Timestamp = time.Time{} + recs[i] = r + } + } + + for _, records := range got { + for _, record := range records { + fmt.Printf("%s: %s: %s\n", record.Timestamp, record.Severity, record.Body) + } + } + + // Output: + // 0001-01-01 00:00:00 +0000 UTC: INFO: Hello there +} From 49486c6c9422b7fc6d70bf0489710fa1a4e1cce6 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:30:08 +0100 Subject: [PATCH 08/40] Refactor --- log/logtest/example_test.go | 31 +++++-------------------------- 1 file changed, 5 insertions(+), 26 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 459b020b529..5794ff040b7 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -16,7 +16,7 @@ func Example() { // Create a recorder. rec := logtest.NewRecorder() - // Emit a record). + // Emit a log record. l := rec.Logger("Example") ctx := context.Background() r := log.Record{} @@ -25,40 +25,19 @@ func Example() { r.SetBody(log.StringValue("Hello there")) l.Emit(ctx, r) - // Check what was recorded. + // Get the recorded log records. got := rec.Result() - for _, records := range got { - for _, record := range records { - fmt.Printf("%s: %s\n", record.Severity, record.Body) - } - } - - // Output: - // INFO: Hello there -} - -func Example_ignoreTimestamp() { - // Create a recorder. - rec := logtest.NewRecorder() - // Emit a record). - l := rec.Logger("Example") - ctx := context.Background() - r := log.Record{} - r.SetTimestamp(time.Now()) - r.SetSeverity(log.SeverityInfo) - r.SetBody(log.StringValue("Hello there")) - l.Emit(ctx, r) - - // Ignore Timestamp. - got := rec.Result() + // Ignore timestamps. for _, recs := range got { for i, r := range recs { r.Timestamp = time.Time{} + r.ObservedTimestamp = time.Time{} recs[i] = r } } + // Print out. for _, records := range got { for _, record := range records { fmt.Printf("%s: %s: %s\n", record.Timestamp, record.Severity, record.Body) From c89f6c9753c26723d6ccda856b7ff60d61cd0714 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:48:42 +0100 Subject: [PATCH 09/40] Better comment --- log/logtest/recorder.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index a1277390867..3e39b75498d 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -192,7 +192,7 @@ func (r *Recorder) Logger(name string, opts ...log.LoggerOption) log.Logger { return l } -// Result returns the current in-memory recorder log records. +// Result returns a deep copy of the current in-memory recorded log records. func (r *Recorder) Result() Result { r.mu.Lock() defer r.mu.Unlock() From 748c27d011f160a8066232545c3be9d5638d19a0 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:52:03 +0100 Subject: [PATCH 10/40] Refactor --- log/logtest/recorder.go | 10 +++++----- log/logtest/recorder_test.go | 4 ++-- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index 3e39b75498d..3f436303732 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -79,11 +79,11 @@ func NewRecorder(options ...Option) *Recorder { } } -// Result represents the recordered log records. -type Result map[Scope][]Record +// RecordedRecords represents the recorded log records snapshot. +type RecordedRecords map[Scope][]Record // Equal returns if a is equal to b. -func (a Result) Equal(b Result) bool { +func (a RecordedRecords) Equal(b RecordedRecords) bool { return maps.EqualFunc(a, b, func(x, y []Record) bool { return slices.EqualFunc(x, y, func(a, b Record) bool { return a.Equal(b) }) }) @@ -193,11 +193,11 @@ func (r *Recorder) Logger(name string, opts ...log.LoggerOption) log.Logger { } // Result returns a deep copy of the current in-memory recorded log records. -func (r *Recorder) Result() Result { +func (r *Recorder) Result() RecordedRecords { r.mu.Lock() defer r.mu.Unlock() - res := make(Result, len(r.loggers)) + res := make(RecordedRecords, len(r.loggers)) for s, l := range r.loggers { l.mu.Lock() recs := make([]Record, len(l.records)) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index ecc2d549415..e3d0dde188d 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -75,7 +75,7 @@ func TestRecorderEmitAndReset(t *testing.T) { recs[i] = r } } - want := Result{ + want := RecordedRecords{ Scope{Name: t.Name()}: []Record{ { Context: ctx, @@ -91,7 +91,7 @@ func TestRecorderEmitAndReset(t *testing.T) { rec.Reset() got = rec.Result() - want = Result{ + want = RecordedRecords{ Scope{Name: t.Name()}: nil, } if !got.Equal(want) { From 96271e943384a1f8bccfaae7c3815c607405eb40 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 19 Feb 2025 23:54:23 +0100 Subject: [PATCH 11/40] Test attributes comparison --- log/logtest/recorder_test.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index e3d0dde188d..0f3d52ca257 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -65,6 +65,8 @@ func TestRecorderEmitAndReset(t *testing.T) { r.SetSeverity(log.SeverityInfo) r.SetTimestamp(time.Now()) r.SetBody(log.StringValue("Hello there")) + r.AddAttributes(log.Int("n", 1)) + r.AddAttributes(log.String("foo", "bar")) l.Emit(ctx, r) got := rec.Result() @@ -81,6 +83,10 @@ func TestRecorderEmitAndReset(t *testing.T) { Context: ctx, Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.String("foo", "bar"), + log.Int("n", 1), + }, }, }, } From e6b7de691b8b19852e3523254d8e4e7d7a69db9e Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 00:29:20 +0100 Subject: [PATCH 12/40] Refactor --- log/logtest/recorder.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index 3f436303732..04841374d87 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -231,12 +231,12 @@ type logger struct { } // Enabled indicates whether a specific record should be stored. -func (l *logger) Enabled(ctx context.Context, opts log.EnabledParameters) bool { +func (l *logger) Enabled(ctx context.Context, param log.EnabledParameters) bool { if l.enabledFn == nil { - return defaultEnabledFunc(ctx, opts) + return defaultEnabledFunc(ctx, param) } - return l.enabledFn(ctx, opts) + return l.enabledFn(ctx, param) } // Emit stores the log record. From 578f9ab786c00af9dbd89de4e5be0b13b2f3afac Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 12:43:23 +0100 Subject: [PATCH 13/40] Rename RecordedRecords to Recording --- log/logtest/recorder.go | 10 +++++----- log/logtest/recorder_test.go | 4 ++-- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index 04841374d87..ca9354d30d8 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -79,11 +79,11 @@ func NewRecorder(options ...Option) *Recorder { } } -// RecordedRecords represents the recorded log records snapshot. -type RecordedRecords map[Scope][]Record +// Recording represents the recorded log records snapshot. +type Recording map[Scope][]Record // Equal returns if a is equal to b. -func (a RecordedRecords) Equal(b RecordedRecords) bool { +func (a Recording) Equal(b Recording) bool { return maps.EqualFunc(a, b, func(x, y []Record) bool { return slices.EqualFunc(x, y, func(a, b Record) bool { return a.Equal(b) }) }) @@ -193,11 +193,11 @@ func (r *Recorder) Logger(name string, opts ...log.LoggerOption) log.Logger { } // Result returns a deep copy of the current in-memory recorded log records. -func (r *Recorder) Result() RecordedRecords { +func (r *Recorder) Result() Recording { r.mu.Lock() defer r.mu.Unlock() - res := make(RecordedRecords, len(r.loggers)) + res := make(Recording, len(r.loggers)) for s, l := range r.loggers { l.mu.Lock() recs := make([]Record, len(l.records)) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 0f3d52ca257..f79a7fe2f5e 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -77,7 +77,7 @@ func TestRecorderEmitAndReset(t *testing.T) { recs[i] = r } } - want := RecordedRecords{ + want := Recording{ Scope{Name: t.Name()}: []Record{ { Context: ctx, @@ -97,7 +97,7 @@ func TestRecorderEmitAndReset(t *testing.T) { rec.Reset() got = rec.Result() - want = RecordedRecords{ + want = Recording{ Scope{Name: t.Name()}: nil, } if !got.Equal(want) { From 9d68e802d876bb4fbb7b48215b41de62b1ba1aff Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 12:56:59 +0100 Subject: [PATCH 14/40] format time --- log/logtest/example_test.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 5794ff040b7..676c636b954 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -40,10 +40,10 @@ func Example() { // Print out. for _, records := range got { for _, record := range records { - fmt.Printf("%s: %s: %s\n", record.Timestamp, record.Severity, record.Body) + fmt.Printf("%s: %s: %s\n", record.Timestamp.Format(time.RFC3339Nano), record.Severity, record.Body) } } // Output: - // 0001-01-01 00:00:00 +0000 UTC: INFO: Hello there + // 0001-01-01T00:00:00Z: INFO: Hello there } From 7443c450af857f4ba3e78172ff07d426a25ed9ac Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 20:30:05 +0100 Subject: [PATCH 15/40] Refactor equals methods to functions --- log/logtest/recorder.go | 23 ++++++++++++++++++----- log/logtest/recorder_test.go | 4 ++-- 2 files changed, 20 insertions(+), 7 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index ca9354d30d8..d6498a47f95 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -6,6 +6,7 @@ package logtest // import "go.opentelemetry.io/otel/log/logtest" import ( "cmp" "context" + "fmt" "maps" "slices" "sync" @@ -79,13 +80,26 @@ func NewRecorder(options ...Option) *Recorder { } } +// Equal returns if a is equal to b. +func Equal[T Recording | Record](a, b T) bool { + switch atyped := interface{}(a).(type) { + case Recording: + return equalRecording(atyped, any(b).(Recording)) + case Record: + return equalRecord(atyped, any(b).(Record)) + } + + // We control all types passed to this, panic to signal developers + // early they changed things in an incompatible way. + panic(fmt.Sprintf("unknown type: %T, %T", a, b)) +} + // Recording represents the recorded log records snapshot. type Recording map[Scope][]Record -// Equal returns if a is equal to b. -func (a Recording) Equal(b Recording) bool { +func equalRecording(a, b Recording) bool { return maps.EqualFunc(a, b, func(x, y []Record) bool { - return slices.EqualFunc(x, y, func(a, b Record) bool { return a.Equal(b) }) + return slices.EqualFunc(x, y, func(a, b Record) bool { return equalRecord(a, b) }) }) } @@ -114,8 +128,7 @@ type Record struct { Attributes []log.KeyValue } -// Equal returns if a is equal to b. -func (a Record) Equal(b Record) bool { +func equalRecord(a, b Record) bool { if a.Context != b.Context { return false } diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index f79a7fe2f5e..b153fc3c523 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -90,7 +90,7 @@ func TestRecorderEmitAndReset(t *testing.T) { }, }, } - if !got.Equal(want) { + if !Equal(got, want) { t.Errorf("Recorded records mismatch\ngot:\n%+v\nwant:\n%+v", got, want) } @@ -100,7 +100,7 @@ func TestRecorderEmitAndReset(t *testing.T) { want = Recording{ Scope{Name: t.Name()}: nil, } - if !got.Equal(want) { + if !Equal(got, want) { t.Errorf("Records should be cleared\ngot:\n%+v\nwant:\n%+v", got, want) } } From 6542559cb6bf374f5925b9b688608405340f74ee Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 21:06:21 +0100 Subject: [PATCH 16/40] Refine Result and add tests --- log/logtest/recorder.go | 20 ++++-- log/logtest/recorder_test.go | 126 +++++++++++++++++++++++++++++++++-- 2 files changed, 132 insertions(+), 14 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index d6498a47f95..de5bbcac08a 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -212,13 +212,19 @@ func (r *Recorder) Result() Recording { res := make(Recording, len(r.loggers)) for s, l := range r.loggers { - l.mu.Lock() - recs := make([]Record, len(l.records)) - for i, r := range l.records { - recs[i] = r.Clone() - } - res[s] = recs - l.mu.Unlock() + func() { + l.mu.Lock() + defer l.mu.Unlock() + if l.records == nil { + res[s] = nil + return + } + recs := make([]Record, len(l.records)) + for i, r := range l.records { + recs[i] = r.Clone() + } + res[s] = recs + }() } return res } diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index b153fc3c523..03faeed16b6 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -9,6 +9,8 @@ import ( "testing" "time" + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" "github.com/stretchr/testify/assert" "go.opentelemetry.io/otel/log" @@ -55,6 +57,118 @@ func TestLoggerEnabledFnUnset(t *testing.T) { assert.True(t, r.Enabled(context.Background(), log.EnabledParameters{})) } +func TestRecordingWithGoCmp(t *testing.T) { + rec := NewRecorder() + + // Emit a record. + l := rec.Logger(t.Name()) + ctx := context.Background() + r := log.Record{} + r.SetSeverity(log.SeverityInfo) + r.SetTimestamp(time.Now()) + r.SetBody(log.StringValue("Hello there")) + r.AddAttributes(log.Int("n", 1)) + r.AddAttributes(log.String("foo", "bar")) + l.Emit(ctx, r) + + got := rec.Result() + want := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Context: ctx, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + // Different order on purpose. + log.String("foo", "bar"), + log.Int("n", 1), + }, + }, + }, + } + seq := cmpopts.EquateComparable(context.Background()) + ordattr := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + ignstamp := cmpopts.IgnoreTypes(time.Time{}) // ignore Timestamps + if diff := cmp.Diff(want, got, seq, ordattr, ignstamp); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } + + rec.Reset() + + got = rec.Result() + want = Recording{ + // Empty slice on purpose. + Scope{Name: t.Name()}: []Record{}, + } + if diff := cmp.Diff(want, got, cmpopts.EquateEmpty()); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } +} + +func TestEqualRecording(t *testing.T) { + a := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + }, + }, + } + b := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.String("foo", "bar"), + log.Int("n", 1), + }, + }, + }, + } + if !Equal(a, b) { + t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", a, b) + } + + a = Recording{ + Scope{Name: t.Name()}: nil, + } + b = Recording{ + // For Equal nil and empty slice is the same. + Scope{Name: t.Name()}: []Record{}, + } + if !Equal(a, b) { + t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", a, b) + } +} + +func TestEqualRecord(t *testing.T) { + a := Record{ + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + } + b := Record{ + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + // Order of attributes is not important. + log.String("foo", "bar"), + log.Int("n", 1), + }, + } + if !Equal(a, b) { + t.Errorf("Record mismatch\na:\n%+v\nb:\n%+v", a, b) + } +} + func TestRecorderEmitAndReset(t *testing.T) { rec := NewRecorder() @@ -84,25 +198,23 @@ func TestRecorderEmitAndReset(t *testing.T) { Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - log.String("foo", "bar"), + // For testify order of attributes is important. log.Int("n", 1), + log.String("foo", "bar"), }, }, }, } - if !Equal(got, want) { - t.Errorf("Recorded records mismatch\ngot:\n%+v\nwant:\n%+v", got, want) - } + assert.Equal(t, want, got) rec.Reset() got = rec.Result() want = Recording{ + // For testify nil and empty slice is imporant. Scope{Name: t.Name()}: nil, } - if !Equal(got, want) { - t.Errorf("Records should be cleared\ngot:\n%+v\nwant:\n%+v", got, want) - } + assert.Equal(t, want, got) } func TestRecorderConcurrentSafe(t *testing.T) { From a84ba4696f4214ca7fe75c571bb8d043eea1e7d4 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 21:49:38 +0100 Subject: [PATCH 17/40] Add example usages --- log/logtest/recorder_test.go | 143 ++++++++++++++++++++--------------- 1 file changed, 84 insertions(+), 59 deletions(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 03faeed16b6..48e27b2870e 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -57,92 +57,123 @@ func TestLoggerEnabledFnUnset(t *testing.T) { assert.True(t, r.Enabled(context.Background(), log.EnabledParameters{})) } -func TestRecordingWithGoCmp(t *testing.T) { - rec := NewRecorder() - - // Emit a record. - l := rec.Logger(t.Name()) - ctx := context.Background() - r := log.Record{} - r.SetSeverity(log.SeverityInfo) - r.SetTimestamp(time.Now()) - r.SetBody(log.StringValue("Hello there")) - r.AddAttributes(log.Int("n", 1)) - r.AddAttributes(log.String("foo", "bar")) - l.Emit(ctx, r) +func TestRecordingEqualWithStdLib(t *testing.T) { + got := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Timestamp: time.Now(), + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.String("foo", "bar"), + log.Int("n", 1), + }, + }, + }, + Scope{Name: "Empty"}: nil, + } - got := rec.Result() want := Recording{ Scope{Name: t.Name()}: []Record{ { - Context: ctx, Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - // Different order on purpose. - log.String("foo", "bar"), log.Int("n", 1), + log.String("foo", "bar"), }, }, }, + Scope{Name: "Empty"}: []Record{}, } - seq := cmpopts.EquateComparable(context.Background()) - ordattr := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - ignstamp := cmpopts.IgnoreTypes(time.Time{}) // ignore Timestamps - if diff := cmp.Diff(want, got, seq, ordattr, ignstamp); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) - } - - rec.Reset() - - got = rec.Result() - want = Recording{ - // Empty slice on purpose. - Scope{Name: t.Name()}: []Record{}, + // Ignore Timestamp. + for _, recs := range got { + for i, r := range recs { + r.Timestamp = time.Time{} + recs[i] = r + } } - if diff := cmp.Diff(want, got, cmpopts.EquateEmpty()); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + if !Equal(want, got) { + t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", want, got) } } -func TestEqualRecording(t *testing.T) { - a := Recording{ +func TestRecordingEqualWithTestify(t *testing.T) { + got := Recording{ Scope{Name: t.Name()}: []Record{ { - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), + Timestamp: time.Now(), + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ + log.Int("n", 1), log.String("foo", "bar"), }, }, }, + Scope{Name: "Empty"}: nil, } - b := Recording{ + + want := Recording{ Scope{Name: t.Name()}: []Record{ { Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - log.String("foo", "bar"), + // Attributes order has to be the same. log.Int("n", 1), + log.String("foo", "bar"), }, }, }, + // Nil and empty slices are different for testify. + Scope{Name: "Empty"}: nil, } - if !Equal(a, b) { - t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", a, b) + // Ignore Timestamp. + for _, recs := range got { + for i, r := range recs { + r.Timestamp = time.Time{} + recs[i] = r + } } + assert.Equal(t, want, got) +} - a = Recording{ - Scope{Name: t.Name()}: nil, +func TestEqualRecordingWithGoCmp(t *testing.T) { + got := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Timestamp: time.Now(), + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.String("foo", "bar"), + log.Int("n", 1), + }, + }, + }, + Scope{Name: "Empty"}: nil, } - b = Recording{ - // For Equal nil and empty slice is the same. - Scope{Name: t.Name()}: []Record{}, + + want := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + }, + }, + Scope{Name: "Empty"}: []Record{}, } - if !Equal(a, b) { - t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", a, b) + seq := cmpopts.EquateComparable(context.Background()) + ordattr := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + ignstamp := cmpopts.IgnoreTypes(time.Time{}) // ignore Timestamps + if diff := cmp.Diff(want, got, seq, ordattr, ignstamp, cmpopts.EquateEmpty()); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } } @@ -171,34 +202,28 @@ func TestEqualRecord(t *testing.T) { func TestRecorderEmitAndReset(t *testing.T) { rec := NewRecorder() + ts := time.Now() // Emit a record. l := rec.Logger(t.Name()) ctx := context.Background() r := log.Record{} r.SetSeverity(log.SeverityInfo) - r.SetTimestamp(time.Now()) + r.SetTimestamp(ts) r.SetBody(log.StringValue("Hello there")) r.AddAttributes(log.Int("n", 1)) r.AddAttributes(log.String("foo", "bar")) l.Emit(ctx, r) got := rec.Result() - // Ignore Timestamp. - for _, recs := range got { - for i, r := range recs { - r.Timestamp = time.Time{} - recs[i] = r - } - } want := Recording{ Scope{Name: t.Name()}: []Record{ { - Context: ctx, - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), + Context: ctx, + Severity: log.SeverityInfo, + Timestamp: ts, + Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - // For testify order of attributes is important. log.Int("n", 1), log.String("foo", "bar"), }, From a4c181dc474ded7a025dede7f40fc1e600b4ab9d Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 22:02:29 +0100 Subject: [PATCH 18/40] Fix build --- log/go.mod | 1 + log/logtest/recorder_test.go | 1 - 2 files changed, 1 insertion(+), 1 deletion(-) diff --git a/log/go.mod b/log/go.mod index acbcedf6360..7404b201be3 100644 --- a/log/go.mod +++ b/log/go.mod @@ -4,6 +4,7 @@ go 1.22.0 require ( github.com/go-logr/logr v1.4.2 + github.com/google/go-cmp v0.6.0 github.com/stretchr/testify v1.10.0 go.opentelemetry.io/otel v1.34.0 ) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 48e27b2870e..d52959294b5 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -106,7 +106,6 @@ func TestRecordingEqualWithTestify(t *testing.T) { Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - log.Int("n", 1), log.String("foo", "bar"), }, From 69a1b373728aacfb7e8f6cd6c6b3588c5c885b47 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Thu, 20 Feb 2025 23:05:59 +0100 Subject: [PATCH 19/40] Fix typo --- log/logtest/recorder_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index d52959294b5..cdfb6f066a8 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -235,7 +235,7 @@ func TestRecorderEmitAndReset(t *testing.T) { got = rec.Result() want = Recording{ - // For testify nil and empty slice is imporant. + // For testify nil and empty slice is important. Scope{Name: t.Name()}: nil, } assert.Equal(t, want, got) From 1b0a436c607c0044fea55f3478add4e19180cb8a Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:27:30 +0100 Subject: [PATCH 20/40] Example to use go-cmp --- log/logtest/example_test.go | 61 ++++++++++++++++++++++++++---------- log/logtest/recorder_test.go | 8 ++--- 2 files changed, 48 insertions(+), 21 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 676c636b954..e8003bd4149 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -8,6 +8,8 @@ import ( "fmt" "time" + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/logtest" ) @@ -16,34 +18,59 @@ func Example() { // Create a recorder. rec := logtest.NewRecorder() - // Emit a log record. + // Emit a log record (code under test). l := rec.Logger("Example") ctx := context.Background() r := log.Record{} r.SetTimestamp(time.Now()) r.SetSeverity(log.SeverityInfo) r.SetBody(log.StringValue("Hello there")) + r.AddAttributes(log.String("fizz", "buzz")) + r.AddAttributes(log.Int("n", 1)) l.Emit(ctx, r) - // Get the recorded log records. - got := rec.Result() - - // Ignore timestamps. - for _, recs := range got { - for i, r := range recs { - r.Timestamp = time.Time{} - r.ObservedTimestamp = time.Time{} - recs[i] = r - } + // Expected log records. + want := logtest.Recording{ + logtest.Scope{Name: "Example"}: []logtest.Record{ + { + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + }, + }, } + // Ignore Context. + cmpCtx := cmpopts.IgnoreFields(logtest.Record{}, "Context") + // Ignore Timestamps. + cmpStmps := cmpopts.IgnoreTypes(time.Time{}) + // Unordered compare of the key values. + cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + // Empty and nil collections are equal. + cmpEpty := cmpopts.EquateEmpty() - // Print out. - for _, records := range got { - for _, record := range records { - fmt.Printf("%s: %s: %s\n", record.Timestamp.Format(time.RFC3339Nano), record.Severity, record.Body) - } + // Get the recorded log records. + got := rec.Result() + if diff := cmp.Diff(got, want, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + fmt.Printf("Recorded records mismatch (-want +got):\n%s", diff) } // Output: - // 0001-01-01T00:00:00Z: INFO: Hello there + // Recorded records mismatch (-want +got): + //   logtest.Recording{ + //    {Name: "Example"}: { + //    { + //    ... // 3 ignored and 2 identical fields + //    SeverityText: "", + //    Body: s"Hello there", + //    Attributes: []log.KeyValue(Inverse(cmpopts.SortSlices, []log.KeyValue{ + // -  s"fizz:buzz", + // +  s"foo:bar", + //    s"n:1", + //    })), + //    }, + //    }, + //   } } diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index cdfb6f066a8..dabaff31c24 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -168,10 +168,10 @@ func TestEqualRecordingWithGoCmp(t *testing.T) { }, Scope{Name: "Empty"}: []Record{}, } - seq := cmpopts.EquateComparable(context.Background()) - ordattr := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - ignstamp := cmpopts.IgnoreTypes(time.Time{}) // ignore Timestamps - if diff := cmp.Diff(want, got, seq, ordattr, ignstamp, cmpopts.EquateEmpty()); diff != "" { + cmpCtx := cmpopts.EquateComparable(context.Background()) + cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + cmpStmps := cmpopts.IgnoreTypes(time.Time{}) + if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpopts.EquateEmpty()); diff != "" { t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } } From 178b0dbf1191533e453a956a1c643ffbb3ecb0bd Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:38:52 +0100 Subject: [PATCH 21/40] Refactor tests --- log/logtest/recorder_test.go | 134 ++++++----------------------------- 1 file changed, 23 insertions(+), 111 deletions(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index dabaff31c24..dea22eb2c52 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -11,16 +11,10 @@ import ( "github.com/google/go-cmp/cmp" "github.com/google/go-cmp/cmp/cmpopts" - "github.com/stretchr/testify/assert" "go.opentelemetry.io/otel/log" ) -func TestRecorderLoggerCreatesNewStruct(t *testing.T) { - r := &Recorder{} - assert.NotEqual(t, r, r.Logger("test")) -} - func TestLoggerEnabled(t *testing.T) { for _, tt := range []struct { name string @@ -46,116 +40,30 @@ func TestLoggerEnabled(t *testing.T) { }, } { t.Run(tt.name, func(t *testing.T) { - e := NewRecorder(tt.options...).Logger("test").Enabled(tt.ctx, tt.enabledParams) - assert.Equal(t, tt.want, e) + got := NewRecorder(tt.options...).Logger("test").Enabled(tt.ctx, tt.enabledParams) + if got != tt.want { + t.Errorf("got: %v, want: %v", got, tt.want) + } }) } } -func TestLoggerEnabledFnUnset(t *testing.T) { - r := &logger{} - assert.True(t, r.Enabled(context.Background(), log.EnabledParameters{})) -} - -func TestRecordingEqualWithStdLib(t *testing.T) { - got := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Timestamp: time.Now(), - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.String("foo", "bar"), - log.Int("n", 1), - }, - }, - }, - Scope{Name: "Empty"}: nil, - } - - want := Recording{ +func TestRecordingEqual(t *testing.T) { + a := Recording{ Scope{Name: t.Name()}: []Record{ { Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ - log.Int("n", 1), log.String("foo", "bar"), - }, - }, - }, - Scope{Name: "Empty"}: []Record{}, - } - // Ignore Timestamp. - for _, recs := range got { - for i, r := range recs { - r.Timestamp = time.Time{} - recs[i] = r - } - } - if !Equal(want, got) { - t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", want, got) - } -} - -func TestRecordingEqualWithTestify(t *testing.T) { - got := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Timestamp: time.Now(), - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ log.Int("n", 1), - log.String("foo", "bar"), }, }, }, Scope{Name: "Empty"}: nil, } - want := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - // Attributes order has to be the same. - log.Int("n", 1), - log.String("foo", "bar"), - }, - }, - }, - // Nil and empty slices are different for testify. - Scope{Name: "Empty"}: nil, - } - // Ignore Timestamp. - for _, recs := range got { - for i, r := range recs { - r.Timestamp = time.Time{} - recs[i] = r - } - } - assert.Equal(t, want, got) -} - -func TestEqualRecordingWithGoCmp(t *testing.T) { - got := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Timestamp: time.Now(), - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.String("foo", "bar"), - log.Int("n", 1), - }, - }, - }, - Scope{Name: "Empty"}: nil, - } - - want := Recording{ + b := Recording{ Scope{Name: t.Name()}: []Record{ { Severity: log.SeverityInfo, @@ -168,11 +76,9 @@ func TestEqualRecordingWithGoCmp(t *testing.T) { }, Scope{Name: "Empty"}: []Record{}, } - cmpCtx := cmpopts.EquateComparable(context.Background()) - cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - cmpStmps := cmpopts.IgnoreTypes(time.Time{}) - if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpopts.EquateEmpty()); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + + if !Equal(b, a) { + t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", b, a) } } @@ -218,10 +124,9 @@ func TestRecorderEmitAndReset(t *testing.T) { want := Recording{ Scope{Name: t.Name()}: []Record{ { - Context: ctx, - Severity: log.SeverityInfo, - Timestamp: ts, - Body: log.StringValue("Hello there"), + Context: ctx, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ log.Int("n", 1), log.String("foo", "bar"), @@ -229,16 +134,23 @@ func TestRecorderEmitAndReset(t *testing.T) { }, }, } - assert.Equal(t, want, got) + cmpCtx := cmpopts.EquateComparable(context.Background()) + cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + cmpStmps := cmpopts.IgnoreTypes(time.Time{}) + cmpEpty := cmpopts.EquateEmpty() + if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } rec.Reset() got = rec.Result() want = Recording{ - // For testify nil and empty slice is important. Scope{Name: t.Name()}: nil, } - assert.Equal(t, want, got) + if diff := cmp.Diff(want, got, cmpEpty); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } } func TestRecorderConcurrentSafe(t *testing.T) { From f26e54387733e3eeae0847f46fdf1206bc500fa7 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:40:47 +0100 Subject: [PATCH 22/40] Refactor --- log/logtest/recorder_test.go | 148 +++++++++++++++++------------------ 1 file changed, 74 insertions(+), 74 deletions(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index dea22eb2c52..6d53a72fcde 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -15,7 +15,55 @@ import ( "go.opentelemetry.io/otel/log" ) -func TestLoggerEnabled(t *testing.T) { +func TestRecorderLoggerEmitAndReset(t *testing.T) { + rec := NewRecorder() + ts := time.Now() + + // Emit a record. + l := rec.Logger(t.Name()) + ctx := context.Background() + r := log.Record{} + r.SetSeverity(log.SeverityInfo) + r.SetTimestamp(ts) + r.SetBody(log.StringValue("Hello there")) + r.AddAttributes(log.Int("n", 1)) + r.AddAttributes(log.String("foo", "bar")) + l.Emit(ctx, r) + + got := rec.Result() + want := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Context: ctx, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + }, + }, + } + cmpCtx := cmpopts.EquateComparable(context.Background()) + cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) + cmpStmps := cmpopts.IgnoreTypes(time.Time{}) + cmpEpty := cmpopts.EquateEmpty() + if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } + + rec.Reset() + + got = rec.Result() + want = Recording{ + Scope{Name: t.Name()}: nil, + } + if diff := cmp.Diff(want, got, cmpEpty); diff != "" { + t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) + } +} + +func TestRecorderLoggerEnabled(t *testing.T) { for _, tt := range []struct { name string options []Option @@ -48,6 +96,30 @@ func TestLoggerEnabled(t *testing.T) { } } +func TestRecorderConcurrentSafe(t *testing.T) { + const goRoutineN = 10 + + var wg sync.WaitGroup + wg.Add(goRoutineN) + + r := &Recorder{} + + for i := 0; i < goRoutineN; i++ { + go func() { + defer wg.Done() + + nr := r.Logger("test") + nr.Enabled(context.Background(), log.EnabledParameters{}) + nr.Emit(context.Background(), log.Record{}) + + r.Result() + r.Reset() + }() + } + + wg.Wait() +} + func TestRecordingEqual(t *testing.T) { a := Recording{ Scope{Name: t.Name()}: []Record{ @@ -82,7 +154,7 @@ func TestRecordingEqual(t *testing.T) { } } -func TestEqualRecord(t *testing.T) { +func TestRecordEqual(t *testing.T) { a := Record{ Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), @@ -104,75 +176,3 @@ func TestEqualRecord(t *testing.T) { t.Errorf("Record mismatch\na:\n%+v\nb:\n%+v", a, b) } } - -func TestRecorderEmitAndReset(t *testing.T) { - rec := NewRecorder() - ts := time.Now() - - // Emit a record. - l := rec.Logger(t.Name()) - ctx := context.Background() - r := log.Record{} - r.SetSeverity(log.SeverityInfo) - r.SetTimestamp(ts) - r.SetBody(log.StringValue("Hello there")) - r.AddAttributes(log.Int("n", 1)) - r.AddAttributes(log.String("foo", "bar")) - l.Emit(ctx, r) - - got := rec.Result() - want := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Context: ctx, - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.Int("n", 1), - log.String("foo", "bar"), - }, - }, - }, - } - cmpCtx := cmpopts.EquateComparable(context.Background()) - cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - cmpStmps := cmpopts.IgnoreTypes(time.Time{}) - cmpEpty := cmpopts.EquateEmpty() - if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) - } - - rec.Reset() - - got = rec.Result() - want = Recording{ - Scope{Name: t.Name()}: nil, - } - if diff := cmp.Diff(want, got, cmpEpty); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) - } -} - -func TestRecorderConcurrentSafe(t *testing.T) { - const goRoutineN = 10 - - var wg sync.WaitGroup - wg.Add(goRoutineN) - - r := &Recorder{} - - for i := 0; i < goRoutineN; i++ { - go func() { - defer wg.Done() - - nr := r.Logger("test") - nr.Enabled(context.Background(), log.EnabledParameters{}) - nr.Emit(context.Background(), log.Record{}) - - r.Result() - r.Reset() - }() - } - - wg.Wait() -} From f8b77630d4990dc02cb9e531baffe7dc3f99433e Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:43:06 +0100 Subject: [PATCH 23/40] Refactor --- log/logtest/recorder_test.go | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-) diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 6d53a72fcde..44c7868d686 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -19,24 +19,23 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { rec := NewRecorder() ts := time.Now() - // Emit a record. l := rec.Logger(t.Name()) ctx := context.Background() r := log.Record{} - r.SetSeverity(log.SeverityInfo) r.SetTimestamp(ts) + r.SetSeverity(log.SeverityInfo) r.SetBody(log.StringValue("Hello there")) r.AddAttributes(log.Int("n", 1)) r.AddAttributes(log.String("foo", "bar")) l.Emit(ctx, r) - got := rec.Result() want := Recording{ Scope{Name: t.Name()}: []Record{ { - Context: ctx, - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), + Context: ctx, + Timestamp: ts, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ log.Int("n", 1), log.String("foo", "bar"), @@ -46,18 +45,18 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { } cmpCtx := cmpopts.EquateComparable(context.Background()) cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - cmpStmps := cmpopts.IgnoreTypes(time.Time{}) cmpEpty := cmpopts.EquateEmpty() - if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + got := rec.Result() + if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpEpty); diff != "" { t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } rec.Reset() - got = rec.Result() want = Recording{ Scope{Name: t.Name()}: nil, } + got = rec.Result() if diff := cmp.Diff(want, got, cmpEpty); diff != "" { t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } From 59b557a9e50197ad1039a903bec86662e561fa8e Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:48:54 +0100 Subject: [PATCH 24/40] remove Equal --- log/logtest/recorder.go | 63 ------------------------------------ log/logtest/recorder_test.go | 57 -------------------------------- 2 files changed, 120 deletions(-) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index de5bbcac08a..fd48c440f94 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -4,11 +4,7 @@ package logtest // import "go.opentelemetry.io/otel/log/logtest" import ( - "cmp" "context" - "fmt" - "maps" - "slices" "sync" "time" @@ -80,29 +76,9 @@ func NewRecorder(options ...Option) *Recorder { } } -// Equal returns if a is equal to b. -func Equal[T Recording | Record](a, b T) bool { - switch atyped := interface{}(a).(type) { - case Recording: - return equalRecording(atyped, any(b).(Recording)) - case Record: - return equalRecord(atyped, any(b).(Record)) - } - - // We control all types passed to this, panic to signal developers - // early they changed things in an incompatible way. - panic(fmt.Sprintf("unknown type: %T, %T", a, b)) -} - // Recording represents the recorded log records snapshot. type Recording map[Scope][]Record -func equalRecording(a, b Recording) bool { - return maps.EqualFunc(a, b, func(x, y []Record) bool { - return slices.EqualFunc(x, y, func(a, b Record) bool { return equalRecord(a, b) }) - }) -} - // Scope represents the instrumentation scope. type Scope struct { // Name is the name of the instrumentation scope. This should be the @@ -128,36 +104,6 @@ type Record struct { Attributes []log.KeyValue } -func equalRecord(a, b Record) bool { - if a.Context != b.Context { - return false - } - if a.EventName != b.EventName { - return false - } - if !a.Timestamp.Equal(b.Timestamp) { - return false - } - if !a.ObservedTimestamp.Equal(b.ObservedTimestamp) { - return false - } - if a.Severity != b.Severity { - return false - } - if a.SeverityText != b.SeverityText { - return false - } - if !a.Body.Equal(b.Body) { - return false - } - aAttrs := sortKVs(a.Attributes) - bAttrs := sortKVs(b.Attributes) - if !slices.EqualFunc(aAttrs, bAttrs, log.KeyValue.Equal) { //nolint:gosimple // We want to use the same pattern. - return false - } - return true -} - // Clone returns a deep copy. func (a Record) Clone() Record { b := a @@ -167,15 +113,6 @@ func (a Record) Clone() Record { return b } -func sortKVs(kvs []log.KeyValue) []log.KeyValue { - s := make([]log.KeyValue, len(kvs)) - copy(s, kvs) - slices.SortFunc(s, func(a, b log.KeyValue) int { - return cmp.Compare(a.Key, b.Key) - }) - return s -} - // Logger returns a copy of Recorder as a [log.Logger] with the provided scope // information. func (r *Recorder) Logger(name string, opts ...log.LoggerOption) log.Logger { diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 44c7868d686..fa4b5618131 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -118,60 +118,3 @@ func TestRecorderConcurrentSafe(t *testing.T) { wg.Wait() } - -func TestRecordingEqual(t *testing.T) { - a := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.String("foo", "bar"), - log.Int("n", 1), - }, - }, - }, - Scope{Name: "Empty"}: nil, - } - - b := Recording{ - Scope{Name: t.Name()}: []Record{ - { - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.Int("n", 1), - log.String("foo", "bar"), - }, - }, - }, - Scope{Name: "Empty"}: []Record{}, - } - - if !Equal(b, a) { - t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", b, a) - } -} - -func TestRecordEqual(t *testing.T) { - a := Record{ - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - log.Int("n", 1), - log.String("foo", "bar"), - }, - } - b := Record{ - Severity: log.SeverityInfo, - Body: log.StringValue("Hello there"), - Attributes: []log.KeyValue{ - // Order of attributes is not important. - log.String("foo", "bar"), - log.Int("n", 1), - }, - } - if !Equal(a, b) { - t.Errorf("Record mismatch\na:\n%+v\nb:\n%+v", a, b) - } -} From 9f19f304171fabad87faf12a69ef6cc74de51fea Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:53:02 +0100 Subject: [PATCH 25/40] gofumpt --- log/logtest/example_test.go | 1 + 1 file changed, 1 insertion(+) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index e8003bd4149..4b0678de0d8 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -10,6 +10,7 @@ import ( "github.com/google/go-cmp/cmp" "github.com/google/go-cmp/cmp/cmpopts" + "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/logtest" ) From 58a907f9d069f4467ac3859732850c20957efd28 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 24 Feb 2025 23:54:56 +0100 Subject: [PATCH 26/40] go mod tidy --- log/go.mod | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/go.mod b/log/go.mod index 7404b201be3..04d97e539f0 100644 --- a/log/go.mod +++ b/log/go.mod @@ -4,7 +4,7 @@ go 1.22.0 require ( github.com/go-logr/logr v1.4.2 - github.com/google/go-cmp v0.6.0 + github.com/google/go-cmp v0.7.0 github.com/stretchr/testify v1.10.0 go.opentelemetry.io/otel v1.34.0 ) From 05acbb68ffe25f0670881b7b5c1be9112a69f32a Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 25 Feb 2025 00:08:30 +0100 Subject: [PATCH 27/40] Make the example stable --- log/logtest/example_test.go | 18 ++---------------- 1 file changed, 2 insertions(+), 16 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 4b0678de0d8..12c4386e7a9 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -26,7 +26,7 @@ func Example() { r.SetTimestamp(time.Now()) r.SetSeverity(log.SeverityInfo) r.SetBody(log.StringValue("Hello there")) - r.AddAttributes(log.String("fizz", "buzz")) + r.AddAttributes(log.String("foo", "bar")) r.AddAttributes(log.Int("n", 1)) l.Emit(ctx, r) @@ -59,19 +59,5 @@ func Example() { } // Output: - // Recorded records mismatch (-want +got): - //   logtest.Recording{ - //    {Name: "Example"}: { - //    { - //    ... // 3 ignored and 2 identical fields - //    SeverityText: "", - //    Body: s"Hello there", - //    Attributes: []log.KeyValue(Inverse(cmpopts.SortSlices, []log.KeyValue{ - // -  s"fizz:buzz", - // +  s"foo:bar", - //    s"n:1", - //    })), - //    }, - //    }, - //   } + // } From 28a6964bd16dfa9f6be698bf0bdcb3216fc68e0a Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 25 Feb 2025 00:30:56 +0100 Subject: [PATCH 28/40] Add changlog entry --- CHANGELOG.md | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 5d56b7daafd..091d7f6bc9a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -38,6 +38,13 @@ The next release will require at least [Go 1.23]. ### Changed - Update `github.com/prometheus/common` to v0.62.0., which changes the `NameValidationScheme` to `NoEscaping`. This allows metrics names to keep original delimiters (e.g. `.`), rather than replacing with underscores. This is controlled by the `Content-Type` header, or can be reverted by setting `NameValidationScheme` to `LegacyValidation` in `github.com/prometheus/common/model`. (#6198) +- Redesign `go.opentelemetry.io/otel/log/logtest`. (#6342) + - Change `Recorder.Result` to return `Recording`. + - Add `Recording`, `Scope`, `Record` types. + - Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types. + - Remove `AssertRecordEqual` function. + - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. + From 16942f1e23348f2fca6822757587c1329f737852 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 25 Feb 2025 00:31:11 +0100 Subject: [PATCH 29/40] Update changelog entry --- CHANGELOG.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 091d7f6bc9a..a9d25d97bb9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -41,10 +41,9 @@ The next release will require at least [Go 1.23]. - Redesign `go.opentelemetry.io/otel/log/logtest`. (#6342) - Change `Recorder.Result` to return `Recording`. - Add `Recording`, `Scope`, `Record` types. + - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. - Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types. - Remove `AssertRecordEqual` function. - - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. - From 145ace32f3334776749eb9b828d0380010238224 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 25 Feb 2025 00:34:45 +0100 Subject: [PATCH 30/40] Update changelog --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index a9d25d97bb9..9f23f53f818 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -41,6 +41,7 @@ The next release will require at least [Go 1.23]. - Redesign `go.opentelemetry.io/otel/log/logtest`. (#6342) - Change `Recorder.Result` to return `Recording`. - Add `Recording`, `Scope`, `Record` types. + - `Recorder` no longer separately stores records emitted by loggers with the same instrumentation scope. - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. - Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types. - Remove `AssertRecordEqual` function. From c42fc68158001f87b2d6c65c319d527fc702cd2a Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 25 Feb 2025 00:47:55 +0100 Subject: [PATCH 31/40] Make Recorder and Record not comparable --- log/logtest/recorder.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index fd48c440f94..dba810a2ff2 100644 --- a/log/logtest/recorder.go +++ b/log/logtest/recorder.go @@ -16,6 +16,9 @@ import ( // Recorder stores all received log records in-memory. // Recorder implements [log.LoggerProvider]. type Recorder struct { + // Ensure forward compatibility by explicitly making this not comparable. + _ [0]func() + embedded.LoggerProvider mu sync.Mutex @@ -94,6 +97,9 @@ type Scope struct { // Record represents the record alongside its context. type Record struct { + // Ensure forward compatibility by explicitly making this not comparable. + _ [0]func() + Context context.Context EventName string Timestamp time.Time From 1486ad53438f6c0f09a83d71e5637514a3e9f078 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Tue, 25 Feb 2025 11:58:59 +0100 Subject: [PATCH 32/40] Update example_test.go --- log/logtest/example_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 12c4386e7a9..4fe059b6ae5 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -54,7 +54,7 @@ func Example() { // Get the recorded log records. got := rec.Result() - if diff := cmp.Diff(got, want, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { fmt.Printf("Recorded records mismatch (-want +got):\n%s", diff) } From dff04ce87f65bc9a2d115319adeaa10b858ebb38 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Tue, 25 Feb 2025 13:54:44 +0100 Subject: [PATCH 33/40] Update example_test.go --- log/logtest/example_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 4fe059b6ae5..8d3967fa5a5 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -55,7 +55,7 @@ func Example() { // Get the recorded log records. got := rec.Result() if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { - fmt.Printf("Recorded records mismatch (-want +got):\n%s", diff) + fmt.Printf("recording mismatch (-want +got):\n%s", diff) } // Output: From 4021498f3cbf59fbeeebec950e054881fc255278 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Wed, 26 Feb 2025 17:43:40 +0100 Subject: [PATCH 34/40] Update log/logtest/example_test.go Co-authored-by: Cheng-Zhen (CZ) Yang --- log/logtest/example_test.go | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 8d3967fa5a5..10afb015c01 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -43,18 +43,15 @@ func Example() { }, }, } - // Ignore Context. - cmpCtx := cmpopts.IgnoreFields(logtest.Record{}, "Context") - // Ignore Timestamps. - cmpStmps := cmpopts.IgnoreTypes(time.Time{}) - // Unordered compare of the key values. - cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - // Empty and nil collections are equal. - cmpEpty := cmpopts.EquateEmpty() - + opts := []cmpopts.Options{ + cmpopts.IgnoreFields(logtest.Record{}, "Context"), // Ignore Context. + cmpopts.IgnoreTypes(time.Time{}), // Ignore Timestamps. + cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. + cmpopts.EquateEmpty(), // Empty and nil collections are equal. + } // Get the recorded log records. got := rec.Result() - if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpStmps, cmpEpty); diff != "" { + if diff := cmp.Diff(want, got, opts...); diff != "" { fmt.Printf("recording mismatch (-want +got):\n%s", diff) } From 348b6157c8fa1a59c2a6ace96a8dbc409c651286 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Wed, 26 Feb 2025 17:49:47 +0100 Subject: [PATCH 35/40] Fix build and refactor --- log/logtest/example_test.go | 8 ++++---- log/logtest/recorder_test.go | 12 +++++++----- 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 10afb015c01..256a26d2bc5 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -43,11 +43,11 @@ func Example() { }, }, } - opts := []cmpopts.Options{ - cmpopts.IgnoreFields(logtest.Record{}, "Context"), // Ignore Context. - cmpopts.IgnoreTypes(time.Time{}), // Ignore Timestamps. + opts := []cmp.Option{ + cmpopts.IgnoreFields(logtest.Record{}, "Context"), // Ignore Context. + cmpopts.IgnoreTypes(time.Time{}), // Ignore Timestamps. cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. - cmpopts.EquateEmpty(), // Empty and nil collections are equal. + cmpopts.EquateEmpty(), // Empty and nil collections are equal. } // Get the recorded log records. got := rec.Result() diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index fa4b5618131..0161524a702 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -43,11 +43,13 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { }, }, } - cmpCtx := cmpopts.EquateComparable(context.Background()) - cmpKVs := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }) - cmpEpty := cmpopts.EquateEmpty() + opts := []cmp.Option{ + cmpopts.EquateComparable(context.Background()), // Compare context. + cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. + cmpopts.EquateEmpty(), // Empty and nil collections are equal. + } got := rec.Result() - if diff := cmp.Diff(want, got, cmpCtx, cmpKVs, cmpEpty); diff != "" { + if diff := cmp.Diff(want, got, opts...); diff != "" { t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } @@ -57,7 +59,7 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { Scope{Name: t.Name()}: nil, } got = rec.Result() - if diff := cmp.Diff(want, got, cmpEpty); diff != "" { + if diff := cmp.Diff(want, got, opts...); diff != "" { t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) } } From 34625462218b9c5e680f46fa4e1bb1677c4377c0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Fri, 7 Mar 2025 18:40:53 +0100 Subject: [PATCH 36/40] Update CHANGELOG.md --- CHANGELOG.md | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 64e8b5fbdda..7754b0f1442 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,19 +8,21 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ## [Unreleased] +### Added + +- Add `Recording`, `Scope`, `Record` types in `go.opentelemetry.io/otel/log/logtest`. (#6342) +- Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. (#6342) + ### Changed -- Redesign `go.opentelemetry.io/otel/log/logtest`. (#6342) - - Change `Recorder.Result` to return `Recording`. - - Add `Recording`, `Scope`, `Record` types. - - `Recorder` no longer separately stores records emitted by loggers with the same instrumentation scope. - - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. - - Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types. - - Remove `AssertRecordEqual` function. +- Change `Recorder.Result` to return `Recording`. (#6342) +- `Recorder` no longer separately stores records emitted by loggers with the same instrumentation scope. (#6342) ### Removed - Drop support for [Go 1.22]. (#6381) +- Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types from `go.opentelemetry.io/otel/log/logtest`. (#6342) +- Remove `AssertRecordEqual` function from `go.opentelemetry.io/otel/log/logtest`. (#6342) From 9c4ddd7cdd455c0d904a83f64d4b6b57918a9990 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Mon, 17 Mar 2025 18:53:49 +0100 Subject: [PATCH 37/40] Better way to compare context --- log/logtest/example_test.go | 5 +++-- log/logtest/recorder_test.go | 2 +- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index 256a26d2bc5..aba5565ee4d 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -34,6 +34,7 @@ func Example() { want := logtest.Recording{ logtest.Scope{Name: "Example"}: []logtest.Record{ { + Context: context.Background(), Severity: log.SeverityInfo, Body: log.StringValue("Hello there"), Attributes: []log.KeyValue{ @@ -44,10 +45,10 @@ func Example() { }, } opts := []cmp.Option{ - cmpopts.IgnoreFields(logtest.Record{}, "Context"), // Ignore Context. + cmp.Comparer(func(x, y context.Context) bool { return x == y }), // Compare context. cmpopts.IgnoreTypes(time.Time{}), // Ignore Timestamps. cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. - cmpopts.EquateEmpty(), // Empty and nil collections are equal. + cmpopts.EquateEmpty(), // Empty and nil collections are equal. } // Get the recorded log records. got := rec.Result() diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 0161524a702..2da43a07daa 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -44,7 +44,7 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { }, } opts := []cmp.Option{ - cmpopts.EquateComparable(context.Background()), // Compare context. + cmp.Comparer(func(x, y context.Context) bool { return x == y }), // Compare context. cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. cmpopts.EquateEmpty(), // Empty and nil collections are equal. } From ecbd5f4686981f86956d5ac7f2af5761c105c86c Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 18 Mar 2025 10:58:45 +0100 Subject: [PATCH 38/40] Add AssertEqual --- CHANGELOG.md | 1 + log/logtest/assert.go | 76 ++++++++++++++++++++++++++++++++++++ log/logtest/example_test.go | 20 +++------- log/logtest/recorder_test.go | 16 +------- 4 files changed, 84 insertions(+), 29 deletions(-) create mode 100644 log/logtest/assert.go diff --git a/CHANGELOG.md b/CHANGELOG.md index f0f8ce31ab9..445525e8926 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ### Added - Add `Recording`, `Scope`, `Record` types in `go.opentelemetry.io/otel/log/logtest`. (#6342) +- Add `AssertEqual` function along with `IgnoreTimestamp` option in `go.opentelemetry.io/otel/log/logtest`. (#6342) - Add a testable example showing how `go.opentelemetry.io/otel/log/logtest` can be used. (#6342) ### Changed diff --git a/log/logtest/assert.go b/log/logtest/assert.go new file mode 100644 index 00000000000..b5a141d58f9 --- /dev/null +++ b/log/logtest/assert.go @@ -0,0 +1,76 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package logtest // import "go.opentelemetry.io/otel/log/logtest" + +import ( + "context" + "fmt" + "time" + + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" + + "go.opentelemetry.io/otel/log" +) + +// TestingT reports failure messages. +// [testing.T] implements this interface. +type TestingT interface { + Errorf(format string, args ...any) +} + +// AssertEqual asserts that the two concrete data-types from the logtest package are equal. +func AssertEqual[T Recording | Record](t TestingT, want, got T, opts ...AssertOption) bool { + if h, ok := t.(interface{ Helper() }); ok { + h.Helper() + } + + cmpOpts := []cmp.Option{ + cmp.Comparer(func(x, y context.Context) bool { return x == y }), // Compare context. + cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. + cmpopts.EquateEmpty(), // Empty and nil collections are equal. + } + + cfg := newAssertConfig(opts) + if cfg.ignoreTimestamp { + cmpOpts = append(cmpOpts, cmpopts.IgnoreTypes(time.Time{})) // Ignore Timestamps. + } + + if diff := cmp.Diff(want, got, cmpOpts...); diff != "" { + fmt.Printf("mismatch (-want +got):\n%s", diff) + return false + } + return true +} + +type assertConfig struct { + ignoreTimestamp bool +} + +func newAssertConfig(opts []AssertOption) assertConfig { + var cfg assertConfig + for _, opt := range opts { + cfg = opt.apply(cfg) + } + return cfg +} + +// AssertOption allows for fine grain control over how AssertEqual operates. +type AssertOption interface { + apply(cfg assertConfig) assertConfig +} + +type fnOption func(cfg assertConfig) assertConfig + +func (fn fnOption) apply(cfg assertConfig) assertConfig { + return fn(cfg) +} + +// IgnoreTimestamp disables checking if timestamps are different. +func IgnoreTimestamp() AssertOption { + return fnOption(func(cfg assertConfig) assertConfig { + cfg.ignoreTimestamp = true + return cfg + }) +} diff --git a/log/logtest/example_test.go b/log/logtest/example_test.go index aba5565ee4d..1fc7b4dbb5d 100644 --- a/log/logtest/example_test.go +++ b/log/logtest/example_test.go @@ -5,17 +5,16 @@ package logtest_test import ( "context" - "fmt" + "testing" "time" - "github.com/google/go-cmp/cmp" - "github.com/google/go-cmp/cmp/cmpopts" - "go.opentelemetry.io/otel/log" "go.opentelemetry.io/otel/log/logtest" ) func Example() { + t := &testing.T{} // Provided by testing framework. + // Create a recorder. rec := logtest.NewRecorder() @@ -30,7 +29,7 @@ func Example() { r.AddAttributes(log.Int("n", 1)) l.Emit(ctx, r) - // Expected log records. + // Verify that the expected and actual log records match. want := logtest.Recording{ logtest.Scope{Name: "Example"}: []logtest.Record{ { @@ -44,17 +43,8 @@ func Example() { }, }, } - opts := []cmp.Option{ - cmp.Comparer(func(x, y context.Context) bool { return x == y }), // Compare context. - cmpopts.IgnoreTypes(time.Time{}), // Ignore Timestamps. - cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. - cmpopts.EquateEmpty(), // Empty and nil collections are equal. - } - // Get the recorded log records. got := rec.Result() - if diff := cmp.Diff(want, got, opts...); diff != "" { - fmt.Printf("recording mismatch (-want +got):\n%s", diff) - } + logtest.AssertEqual(t, want, got, logtest.IgnoreTimestamp()) // Output: // diff --git a/log/logtest/recorder_test.go b/log/logtest/recorder_test.go index 2da43a07daa..5e247d9a085 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -9,9 +9,6 @@ import ( "testing" "time" - "github.com/google/go-cmp/cmp" - "github.com/google/go-cmp/cmp/cmpopts" - "go.opentelemetry.io/otel/log" ) @@ -43,15 +40,8 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { }, }, } - opts := []cmp.Option{ - cmp.Comparer(func(x, y context.Context) bool { return x == y }), // Compare context. - cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key }), // Unordered compare of the key values. - cmpopts.EquateEmpty(), // Empty and nil collections are equal. - } got := rec.Result() - if diff := cmp.Diff(want, got, opts...); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) - } + AssertEqual(t, want, got) rec.Reset() @@ -59,9 +49,7 @@ func TestRecorderLoggerEmitAndReset(t *testing.T) { Scope{Name: t.Name()}: nil, } got = rec.Result() - if diff := cmp.Diff(want, got, opts...); diff != "" { - t.Errorf("Recorded records mismatch (-want +got):\n%s", diff) - } + AssertEqual(t, want, got) } func TestRecorderLoggerEnabled(t *testing.T) { From 457ca73b6563a01506edb2e6d9d4463894ae928c Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 18 Mar 2025 12:04:58 +0100 Subject: [PATCH 39/40] Fix AssertEqual --- log/logtest/assert.go | 3 +- log/logtest/assert_test.go | 174 +++++++++++++++++++++++++++++++++++++ 2 files changed, 175 insertions(+), 2 deletions(-) create mode 100644 log/logtest/assert_test.go diff --git a/log/logtest/assert.go b/log/logtest/assert.go index b5a141d58f9..28321437b4b 100644 --- a/log/logtest/assert.go +++ b/log/logtest/assert.go @@ -5,7 +5,6 @@ package logtest // import "go.opentelemetry.io/otel/log/logtest" import ( "context" - "fmt" "time" "github.com/google/go-cmp/cmp" @@ -38,7 +37,7 @@ func AssertEqual[T Recording | Record](t TestingT, want, got T, opts ...AssertOp } if diff := cmp.Diff(want, got, cmpOpts...); diff != "" { - fmt.Printf("mismatch (-want +got):\n%s", diff) + t.Errorf("mismatch (-want +got):\n%s", diff) return false } return true diff --git a/log/logtest/assert_test.go b/log/logtest/assert_test.go new file mode 100644 index 00000000000..f280a658ae6 --- /dev/null +++ b/log/logtest/assert_test.go @@ -0,0 +1,174 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package logtest + +import ( + "context" + "testing" + "time" + + "go.opentelemetry.io/otel/log" +) + +var y2k = time.Date(2000, time.January, 1, 0, 0, 0, 0, time.UTC) + +type mockTestingT struct { + errors []string +} + +func (m *mockTestingT) Errorf(format string, args ...any) { + m.errors = append(m.errors, format) +} + +func TestAssertEqualRecording(t *testing.T) { + tests := []struct { + name string + a Recording + b Recording + opts []AssertOption + want bool + }{ + { + name: "equal recordings", + a: Recording{ + Scope{Name: t.Name()}: []Record{ + {Timestamp: y2k, Context: context.Background(), Attributes: []log.KeyValue{log.Int("n", 1), log.String("foo", "bar")}}, + }, + }, + b: Recording{ + Scope{Name: t.Name()}: []Record{ + {Timestamp: y2k, Context: context.Background(), Attributes: []log.KeyValue{log.String("foo", "bar"), log.Int("n", 1)}}, + }, + }, + want: true, + }, + { + name: "different recordings", + a: Recording{ + Scope{Name: t.Name()}: []Record{ + {Attributes: []log.KeyValue{log.String("foo", "bar")}}, + }, + }, + b: Recording{ + Scope{Name: t.Name()}: []Record{ + {Attributes: []log.KeyValue{log.Int("n", 1)}}, + }, + }, + want: false, + }, + { + name: "equal empty scopes", + a: Recording{ + Scope{Name: t.Name()}: nil, + }, + b: Recording{ + Scope{Name: t.Name()}: []Record{}, + }, + want: true, + }, + { + name: "equal empty attributes", + a: Recording{ + Scope{Name: t.Name()}: []Record{ + {Body: log.StringValue("msg"), Attributes: []log.KeyValue{}}, + }, + }, + b: Recording{ + Scope{Name: t.Name()}: []Record{ + {Body: log.StringValue("msg"), Attributes: nil}, + }, + }, + want: true, + }, + { + name: "ignore timestamp", + a: Recording{ + Scope{Name: t.Name()}: []Record{ + {Timestamp: y2k, Attributes: []log.KeyValue{log.String("foo", "bar")}}, + }, + }, + b: Recording{ + Scope{Name: t.Name()}: []Record{ + {Timestamp: time.Now(), Attributes: []log.KeyValue{log.String("foo", "bar")}}, + }, + }, + opts: []AssertOption{IgnoreTimestamp()}, + want: true, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + mockT := &mockTestingT{} + result := AssertEqual(mockT, tc.a, tc.b, tc.opts...) + if result != tc.want { + t.Errorf("AssertEqual() = %v, want %v", result, tc.want) + } + if !tc.want && len(mockT.errors) == 0 { + t.Errorf("expected Errorf call but got none") + } + }) + } +} + +func TestAssertEqualRecord(t *testing.T) { + tests := []struct { + name string + a Record + b Record + opts []AssertOption + want bool + }{ + { + name: "equal records", + a: Record{ + Timestamp: y2k, + Context: context.Background(), + Attributes: []log.KeyValue{log.Int("n", 1), log.String("foo", "bar")}, + }, + b: Record{ + Timestamp: y2k, + Context: context.Background(), + Attributes: []log.KeyValue{log.String("foo", "bar"), log.Int("n", 1)}, + }, + want: true, + }, + { + name: "different records", + a: Record{ + Attributes: []log.KeyValue{log.String("foo", "bar")}, + }, + b: Record{ + Attributes: []log.KeyValue{log.Int("n", 1)}, + }, + want: false, + }, + { + name: "ignore timestamp", + a: Record{ + Timestamp: y2k, + Attributes: []log.KeyValue{log.String("foo", "bar")}, + }, + b: Record{ + Timestamp: time.Now(), + Attributes: []log.KeyValue{log.String("foo", "bar")}, + }, + opts: []AssertOption{IgnoreTimestamp()}, + want: true, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + mockT := &mockTestingT{} + result := AssertEqual(mockT, tc.a, tc.b, tc.opts...) + if result != tc.want { + t.Errorf("AssertEqual() = %v, want %v", result, tc.want) + } + if !tc.want && len(mockT.errors) == 0 { + t.Errorf("expected Errorf call but got none") + } + }) + } +} From d33aea9005f4efd3de880602ebcd2a133f259412 Mon Sep 17 00:00:00 2001 From: Robert Pajak Date: Tue, 18 Mar 2025 12:06:17 +0100 Subject: [PATCH 40/40] Fix changelog --- CHANGELOG.md | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3720e1bcdb9..304ac8219c5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,25 +16,22 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ### Changed +- ⚠️ Update `github.com/prometheus/client_golang` to `v1.21.1`, which changes the `NameValidationScheme` to `UTF8Validation`. + This allows metrics names to keep original delimiters (e.g. `.`), rather than replacing with underscores. + This can be reverted by setting `github.com/prometheus/common/model.NameValidationScheme` to `LegacyValidation` in `github.com/prometheus/common/model`. (#6433) - Change `Recorder.Result` to return `Recording`. (#6342) - `Recorder` no longer separately stores records emitted by loggers with the same instrumentation scope. (#6342) +### Fixes + +- Stop percent encoding header environment variables in `go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc` and `go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp`. (#6392) + ### Removed - Drop support for [Go 1.22]. (#6381, #6418) - Remove `ScopeRecords`, `EmittedRecord`, `RecordFactory` types from `go.opentelemetry.io/otel/log/logtest`. (#6342) - Remove `AssertRecordEqual` function from `go.opentelemetry.io/otel/log/logtest`. (#6342) -### Changed - -- ⚠️ Update `github.com/prometheus/client_golang` to `v1.21.1`, which changes the `NameValidationScheme` to `UTF8Validation`. - This allows metrics names to keep original delimiters (e.g. `.`), rather than replacing with underscores. - This can be reverted by setting `github.com/prometheus/common/model.NameValidationScheme` to `LegacyValidation` in `github.com/prometheus/common/model`. (#6433) - -### Fixes - -- Stop percent encoding header environment variables in `go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploggrpc` and `go.opentelemetry.io/otel/exporters/otlp/otlplog/otlploghttp`. (#6392) -