log/logtest: Change Recorder.Result

Author: pellared

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,126 +60,175 @@ 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
 	// SchemaURL of the telemetry emitted by the scope.
 	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 {
+	// Ensure forward compatibility by explicitly making this not comparable.
+	_ [0]func()
 
-// Context provides the context emitted with the record.
-func (rwc EmittedRecord) Context() context.Context {
-	return rwc.ctx
+	Context           context.Context
+	EventName         string
+	Timestamp         time.Time
+	ObservedTimestamp time.Time
+	Severity          log.Severity
+	SeverityText      string
+	Body              log.Value
+	Attributes        []log.KeyValue
 }
 
-// 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...)
-
-	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 {
+// Reset clears the in-memory log records for all loggers.
+func (r *Recorder) Reset() {
 	r.mu.Lock()
 	defer r.mu.Unlock()
 
-	ret := []*ScopeRecords{}
 	for _, l := range r.loggers {
-		ret = append(ret, l.scopeRecord)
+		l.Reset()
 	}
-	return ret
 }
 
-// Reset clears the in-memory log records for all loggers.
-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()
 
-	for _, l := range r.loggers {
-		l.Reset()
+	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.
 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.
 func (l *logger) Reset() {
 	l.mu.Lock()
 	defer l.mu.Unlock()
 
-	l.scopeRecord.Records = nil
+	l.records = nil
 }

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)
+
+	l2 := rec.Logger(t.Name())
+	r2 := log.Record{}
+	r2.SetBody(log.StringValue("Logger with the same scope"))
+	l2.Emit(ctx, r2)
+
+	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)
 
-	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)
+	rec.Reset()
 
-	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)
-
-	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) {