diff --git a/CHANGELOG.md b/CHANGELOG.md index 41f736a0b..687e493e2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,12 +14,14 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - The `go.opentelemetry.io/otel/semconv/v1.31.0` package. The package contains semantic conventions from the `v1.31.0` version of the OpenTelemetry Semantic Conventions. See the [migration documentation](./semconv/v1.31.0/MIGRATION.md) for information on how to upgrade from `go.opentelemetry.io/otel/semconv/v1.30.0`(#6479) +- Add `Recording`, `Scope`, and `Record` types in `go.opentelemetry.io/otel/log/logtest`. (#6507) ### Removed - Drop support for [Go 1.22]. (#6381, #6418) - Remove `Resource` field from `EnabledParameters` in `go.opentelemetry.io/otel/sdk/log`. (#6494) - Remove `RecordFactory` type from `go.opentelemetry.io/otel/log/logtest`. (#6492) +- Remove `ScopeRecords`, `EmittedRecord`, and `RecordFactory` types from `go.opentelemetry.io/otel/log/logtest`. (#6507) ### Changed @@ -29,6 +31,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - Initialize map with `len(keys)` in `NewAllowKeysFilter` and `NewDenyKeysFilter` to avoid unnecessary allocations in `go.opentelemetry.io/otel/attribute`. (#6455) - `go.opentelemetry.io/otel/log/logtest` is now a separate Go module. (#6465) - `go.opentelemetry.io/otel/sdk/log/logtest` is now a separate Go module. (#6466) +- `Recorder` in `go.opentelemetry.io/otel/log/logtest` no longer separately stores records emitted by loggers with the same instrumentation scope. (#6507) - Improve performance of `BatchProcessor` in `go.opentelemetry.io/otel/sdk/log` by not exporting when exporter cannot accept more. (#6569, #6641) ### Deprecated diff --git a/log/logtest/recorder.go b/log/logtest/recorder.go index fd986c9af..a6c509705 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 ( "context" "sync" + "time" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/log" @@ -59,9 +60,13 @@ func NewRecorder(options ...Option) *Recorder { } } -// ScopeRecords represents the records for a single instrumentation scope. -type ScopeRecords struct { - // Name is the name of the instrumentation scope. +// Recording represents the recorded log records snapshot. +type Recording map[Scope][]Record + +// 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 +74,77 @@ 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 +// Record represents the record alongside its context. +type Record struct { + // Ensure forward compatibility by explicitly making this not comparable. + _ [0]func() - ctx context.Context + 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 -} - -// Recorder is a recorder that stores all received log records -// in-memory. +// 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 - loggers []*logger + 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) + +// 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 +} + // 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...) + scope := Scope{ + Name: name, + Version: cfg.InstrumentationVersion(), + SchemaURL: cfg.SchemaURL(), + Attributes: cfg.InstrumentationAttributes(), + } - nl := &logger{ - scopeRecord: &ScopeRecords{ - Name: name, - Version: cfg.InstrumentationVersion(), - SchemaURL: cfg.SchemaURL(), - Attributes: cfg.InstrumentationAttributes(), - }, + r.mu.Lock() + defer r.mu.Unlock() + + 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.addChildLogger(nl) - - return nl -} - -func (r *Recorder) addChildLogger(nl *logger) { - r.mu.Lock() - defer r.mu.Unlock() - - r.loggers = append(r.loggers, nl) -} - -// Result returns the current in-memory recorder log records. -func (r *Recorder) Result() []*ScopeRecords { - r.mu.Lock() - defer r.mu.Unlock() - - ret := []*ScopeRecords{} - for _, l := range r.loggers { - ret = append(ret, l.scopeRecord) - } - return ret + r.loggers[scope] = l + return l } // Reset clears the in-memory log records for all loggers. @@ -148,23 +157,47 @@ func (r *Recorder) Reset() { } } +// Result returns a deep copy of the current in-memory recorded log records. +func (r *Recorder) Result() Recording { + r.mu.Lock() + defer r.mu.Unlock() + + res := make(Recording, len(r.loggers)) + for s, l := range r.loggers { + 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 +} + 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 } // 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. @@ -172,7 +205,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 +230,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 28d814528..b44b17070 100644 --- a/log/logtest/recorder_test.go +++ b/log/logtest/recorder_test.go @@ -7,6 +7,7 @@ import ( "context" "sync" "testing" + "time" "github.com/stretchr/testify/assert" @@ -22,41 +23,37 @@ func TestRecorderLogger(t *testing.T) { loggerName string loggerOptions []log.LoggerOption - wantLogger log.Logger + want Recording }{ { - name: "provides a default logger", - - wantLogger: &logger{ - scopeRecord: &ScopeRecords{}, + name: "default scope", + want: Recording{ + Scope{}: nil, }, }, { - name: "provides a logger with a configured scope", - + name: "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{ + want: Recording{ + Scope{ Name: "test", Version: "logtest v42", SchemaURL: "https://example.com", Attributes: attribute.NewSet(attribute.String("foo", "bar")), - }, + }: nil, }, }, } { 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) + rec := NewRecorder(tt.options...) + rec.Logger(tt.loggerName, tt.loggerOptions...) + got := rec.Result() + assert.Equal(t, tt.want, got) }) } } @@ -102,41 +99,54 @@ func TestLoggerEnabledFnUnset(t *testing.T) { assert.True(t, r.Enabled(context.Background(), log.EnabledParameters{})) } -func TestRecorderEmitAndReset(t *testing.T) { - r := NewRecorder() - l := r.Logger("test") - assert.Empty(t, r.Result()[0].Records) +func TestRecorderLoggerEmitAndReset(t *testing.T) { + rec := NewRecorder() + ts := time.Now() - r1 := log.Record{} - r1.SetSeverity(log.SeverityInfo) + l := rec.Logger(t.Name()) ctx := context.Background() + r := log.Record{} + 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) - 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) - + l2 := rec.Logger(t.Name()) 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() + r2.SetBody(log.StringValue("Logger with the same scope")) + l2.Emit(ctx, r2) - 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) + want := Recording{ + Scope{Name: t.Name()}: []Record{ + { + Context: ctx, + Timestamp: ts, + Severity: log.SeverityInfo, + Body: log.StringValue("Hello there"), + Attributes: []log.KeyValue{ + log.Int("n", 1), + log.String("foo", "bar"), + }, + }, + { + Context: ctx, + Body: log.StringValue("Logger with the same scope"), + Attributes: []log.KeyValue{}, + }, + }, + } + got := rec.Result() + assert.Equal(t, want, got) - 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) + want = Recording{ + Scope{Name: t.Name()}: nil, + } + got = rec.Result() + assert.Equal(t, want, got) } func TestRecorderConcurrentSafe(t *testing.T) {