diff --git a/log/event.go b/log/event.go new file mode 100644 index 00000000000..c598cafbd28 --- /dev/null +++ b/log/event.go @@ -0,0 +1,129 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package log // import "go.opentelemetry.io/otel/log" + +import ( + "slices" + "time" +) + +// eventAttributesInlineCount is the number of attributes that are efficiently +// stored in an array within an Event. +const eventAttributesInlineCount = 5 + +// Event represents an OpenTelemetry event. +type Event struct { + // Ensure forward compatibility by explicitly making this not comparable. + noCmp [0]func() //nolint: unused // This is indeed used. + + timestamp time.Time + observedTimestamp time.Time + severity Severity + severityText string + body Value + + // The fields below are for optimizing the implementation of Attributes and + // AddAttributes. This design is borrowed from the slog Record type: + // https://cs.opensource.google/go/go/+/refs/tags/go1.22.0:src/log/slog/record.go;l=20 + + // Allocation optimization: an inline array sized to hold + // the majority of event calls (based on examination of + // OpenTelemetry Semantic Conventions for Events). + // It holds the start of the list of attributes. + front [eventAttributesInlineCount]KeyValue + + // The number of attributes in front. + nFront int + + // The list of attributes except for those in front. + // Invariants: + // - len(back) > 0 if nFront == len(front) + // - Unused array elements are zero-ed. Used to detect mistakes. + back []KeyValue +} + +// Timestamp returns the time when the event occurred. +func (r *Event) Timestamp() time.Time { + return r.timestamp +} + +// SetTimestamp sets the time when the event occurred. +func (r *Event) SetTimestamp(t time.Time) { + r.timestamp = t +} + +// ObservedTimestamp returns the time when the event was observed. +func (r *Event) ObservedTimestamp() time.Time { + return r.observedTimestamp +} + +// SetObservedTimestamp sets the time when the event was observed. +func (r *Event) SetObservedTimestamp(t time.Time) { + r.observedTimestamp = t +} + +// Severity returns the [Severity] of the event. +func (r *Event) Severity() Severity { + return r.severity +} + +// SetSeverity sets the [Severity] level of the event. +func (r *Event) SetSeverity(level Severity) { + r.severity = level +} + +// SeverityText returns severity (also known as log level) text. This is the +// original string representation of the severity as it is known at the source. +func (r *Event) SeverityText() string { + return r.severityText +} + +// SetSeverityText sets severity (also known as log level) text. This is the +// original string representation of the severity as it is known at the source. +func (r *Event) SetSeverityText(text string) { + r.severityText = text +} + +// Body returns the body of the event. +func (r *Event) Body() Value { + return r.body +} + +// SetBody sets the body of the event. +func (r *Event) SetBody(v Value) { + r.body = v +} + +// WalkAttributes walks all attributes the event holds by calling f for +// each on each [KeyValue] in the [Record]. Iteration stops if f returns false. +func (r *Event) WalkAttributes(f func(KeyValue) bool) { + for i := 0; i < r.nFront; i++ { + if !f(r.front[i]) { + return + } + } + for _, a := range r.back { + if !f(a) { + return + } + } +} + +// AddAttributes adds attributes to the event. +func (r *Event) AddAttributes(attrs ...KeyValue) { + var i int + for i = 0; i < len(attrs) && r.nFront < len(r.front); i++ { + a := attrs[i] + r.front[r.nFront] = a + r.nFront++ + } + + r.back = slices.Grow(r.back, len(attrs[i:])) + r.back = append(r.back, attrs[i:]...) +} + +// AttributesLen returns the number of attributes in the event. +func (r *Event) AttributesLen() int { + return r.nFront + len(r.back) +} diff --git a/log/event_bench_test.go b/log/event_bench_test.go new file mode 100644 index 00000000000..b7dd8b072b1 --- /dev/null +++ b/log/event_bench_test.go @@ -0,0 +1,109 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package log_test + +import ( + "testing" + "time" + + "go.opentelemetry.io/otel/log" +) + +func BenchmarkEvent(b *testing.B) { + var ( + tStamp time.Time + sev log.Severity + text string + body log.Value + attr log.KeyValue + n int + ) + + b.Run("Timestamp", func(b *testing.B) { + b.ReportAllocs() + for n := 0; n < b.N; n++ { + var e log.Event + e.SetTimestamp(y2k) + tStamp = e.Timestamp() + } + }) + + b.Run("ObservedTimestamp", func(b *testing.B) { + b.ReportAllocs() + for n := 0; n < b.N; n++ { + var e log.Event + e.SetObservedTimestamp(y2k) + tStamp = e.ObservedTimestamp() + } + }) + + b.Run("Severity", func(b *testing.B) { + b.ReportAllocs() + for n := 0; n < b.N; n++ { + var e log.Event + e.SetSeverity(log.SeverityDebug) + sev = e.Severity() + } + }) + + b.Run("SeverityText", func(b *testing.B) { + b.ReportAllocs() + for n := 0; n < b.N; n++ { + var e log.Event + e.SetSeverityText("text") + text = e.SeverityText() + } + }) + + bodyVal := log.BoolValue(true) + b.Run("Body", func(b *testing.B) { + b.ReportAllocs() + for n := 0; n < b.N; n++ { + var e log.Event + e.SetBody(bodyVal) + body = e.Body() + } + }) + + attrs10 := []log.KeyValue{ + log.Bool("b1", true), + log.Int("i1", 324), + log.Float64("f1", -230.213), + log.String("s1", "value1"), + log.Map("m1", log.Slice("slice1", log.BoolValue(true))), + log.Bool("b2", false), + log.Int("i2", 39847), + log.Float64("f2", 0.382964329), + log.String("s2", "value2"), + log.Map("m2", log.Slice("slice2", log.BoolValue(false))), + } + attrs5 := attrs10[:5] + walk := func(kv log.KeyValue) bool { + attr = kv + return true + } + b.Run("Attributes", func(b *testing.B) { + b.Run("5", func(b *testing.B) { + b.ReportAllocs() + for i := 0; i < b.N; i++ { + var e log.Event + e.AddAttributes(attrs5...) + n = e.AttributesLen() + e.WalkAttributes(walk) + } + }) + b.Run("10", func(b *testing.B) { + b.ReportAllocs() + for i := 0; i < b.N; i++ { + var e log.Event + e.AddAttributes(attrs10...) + n = e.AttributesLen() + e.WalkAttributes(walk) + } + }) + }) + + // Convince the linter these values are used. + _, _, _, _, _, _ = tStamp, sev, text, body, attr, n +} diff --git a/log/event_test.go b/log/event_test.go new file mode 100644 index 00000000000..6115814e5e6 --- /dev/null +++ b/log/event_test.go @@ -0,0 +1,152 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +package log_test + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + + "go.opentelemetry.io/otel/log" +) + +func TestEventTimestamp(t *testing.T) { + var e log.Event + e.SetTimestamp(y2k) + assert.Equal(t, y2k, e.Timestamp()) +} + +func TestEventObservedTimestamp(t *testing.T) { + var e log.Event + e.SetObservedTimestamp(y2k) + assert.Equal(t, y2k, e.ObservedTimestamp()) +} + +func TestEventSeverity(t *testing.T) { + var e log.Event + e.SetSeverity(log.SeverityInfo) + assert.Equal(t, log.SeverityInfo, e.Severity()) +} + +func TestEventSeverityText(t *testing.T) { + const text = "testing text" + + var e log.Event + e.SetSeverityText(text) + assert.Equal(t, text, e.SeverityText()) +} + +func TestEventBody(t *testing.T) { + body := log.StringValue("testing body value") + + var e log.Event + e.SetBody(body) + assert.Equal(t, body, e.Body()) +} + +func TestEventAttributes(t *testing.T) { + attrs := []log.KeyValue{ + log.String("k1", "str"), + log.Float64("k2", 1.0), + log.Int("k3", 2), + log.Bool("k4", true), + log.Bytes("k5", []byte{1}), + log.Slice("k6", log.IntValue(3)), + log.Map("k7", log.Bool("sub1", true)), + log.String("k8", "str"), + log.Float64("k9", 1.0), + log.Int("k10", 2), + log.Bool("k11", true), + log.Bytes("k12", []byte{1}), + log.Slice("k13", log.IntValue(3)), + log.Map("k14", log.Bool("sub1", true)), + {}, // Empty. + } + + var e log.Event + e.AddAttributes(attrs...) + require.Equal(t, len(attrs), e.AttributesLen()) + + t.Run("Correctness", func(t *testing.T) { + var i int + e.WalkAttributes(func(kv log.KeyValue) bool { + assert.Equal(t, attrs[i], kv) + i++ + return true + }) + }) + + t.Run("WalkAttributes/Filtering", func(t *testing.T) { + for i := 1; i <= len(attrs); i++ { + var j int + e.WalkAttributes(func(log.KeyValue) bool { + j++ + return j < i + }) + assert.Equal(t, i, j, "number of attributes walked incorrect") + } + }) +} + +func TestEventAllocationLimits(t *testing.T) { + const runs = 5 + + // Assign testing results to external scope so the compiler doesn't + // optimize away the testing statements. + var ( + tStamp time.Time + sev log.Severity + text string + body log.Value + n int + attr log.KeyValue + ) + + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.SetTimestamp(y2k) + tStamp = e.Timestamp() + }), "Timestamp") + + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.SetObservedTimestamp(y2k) + tStamp = e.ObservedTimestamp() + }), "ObservedTimestamp") + + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.SetSeverity(log.SeverityDebug) + sev = e.Severity() + }), "Severity") + + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.SetSeverityText("severity text") + text = e.SeverityText() + }), "SeverityText") + + bodyVal := log.BoolValue(true) + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.SetBody(bodyVal) + body = e.Body() + }), "Body") + + attrVal := []log.KeyValue{log.Bool("k", true), log.Int("i", 1)} + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + var e log.Event + e.AddAttributes(attrVal...) + n = e.AttributesLen() + e.WalkAttributes(func(kv log.KeyValue) bool { + attr = kv + return true + }) + }), "Attributes") + + // Convince the linter these values are used. + _, _, _, _, _, _ = tStamp, sev, text, body, n, attr +}