From b353d83cd92b951be8806421c72768249d55239b Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 11:15:05 -0700 Subject: [PATCH 01/13] Replace Record lim methods with DroppedAttributes --- sdk/log/record.go | 139 +++++++++++++++++++++++++++++++++++------ sdk/log/record_test.go | 14 ----- 2 files changed, 119 insertions(+), 34 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 33e1c86c74f..395e678b9ce 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -48,6 +48,10 @@ type Record struct { // - Unused array elements are zero-ed. Used to detect mistakes. back []log.KeyValue + // dropped is the count of attributes that have been dropped when limits + // were reached. + dropped int + traceID trace.TraceID spanID trace.SpanID traceFlags trace.TraceFlags @@ -131,6 +135,26 @@ func (r *Record) WalkAttributes(f func(log.KeyValue) bool) { // AddAttributes adds attributes to the log record. func (r *Record) AddAttributes(attrs ...log.KeyValue) { + if r.attributeCountLimit > 0 { + if r.AttributesLen()+len(attrs) > r.attributeCountLimit { + r.compactAttr() + // TODO: apply truncation to string and []string values. + var dropped int + attrs, dropped = deduplicate(attrs) + r.dropped += dropped + + if n := r.AttributesLen(); n+len(attrs) > r.attributeCountLimit { + last := max(0, (r.attributeCountLimit - n)) + r.dropped += len(attrs) - last + attrs = attrs[:last] + } + } + } + + r.addAttributes(attrs) +} + +func (r *Record) addAttributes(attrs []log.KeyValue) { var i int for i = 0; i < len(attrs) && r.nFront < len(r.front); i++ { a := attrs[i] @@ -142,8 +166,97 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) { r.back = append(r.back, attrs[i:]...) } +func (r *Record) compactAttr() { + var dropped int + // index holds the location of attributes in the record based on the + // attribute key. If the value stored is < 0 the -(value + 1) (e.g. -1 -> + // 0, -2 -> 1, -3 -> 2) represents the index in r.nFront. Otherwise, the + // index is exact index of r.back. + index := make(map[string]int) + var cursor int + for i := 0; i < r.nFront; i++ { + key := r.front[i].Key + idx, found := index[key] + if found { + dropped++ + r.front[-(idx + 1)] = r.front[i] + } else { + r.front[cursor] = r.front[i] + index[key] = -cursor - 1 // stored in front: negative index. + cursor++ + } + } + r.nFront -= dropped + + for cursor < attributesInlineCount && len(r.back) > 0 { + key := r.back[0].Key + idx, found := index[key] + if found { + dropped++ + r.front[-(idx + 1)] = r.back[0] + } else { + r.front[cursor] = r.back[0] + r.nFront++ + + index[key] = -cursor - 1 // stored in front: negative index. + cursor++ + } + r.back = r.back[1:] + } + + for i, a := range r.back { + key := a.Key + idx, found := index[key] + if found { + dropped++ + if idx < 0 { + r.front[-(idx + 1)] = a + } else { + r.back[idx] = a // stored in back: positive index. + } + r.back = append(r.back[:i], r.back[i+1:]...) + } else { + index[key] = i + } + } + + r.dropped += dropped +} + // SetAttributes sets (and overrides) attributes to the log record. func (r *Record) SetAttributes(attrs ...log.KeyValue) { + // If adding these attributes could exceed limit, de-duplicate to minimize + // overflow. + if r.attributeCountLimit > 0 && len(attrs) > r.attributeCountLimit { + // TODO: apply truncation to string and []string values. + attrs, r.dropped = deduplicate(attrs) + if len(attrs) > r.attributeCountLimit { + r.dropped += len(attrs) - r.attributeCountLimit + attrs = attrs[:r.attributeCountLimit] + } + } + + r.setAttributes(attrs) +} + +func deduplicate(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { + unique = kvs[:0] + + index := make(map[string]int) + for _, a := range kvs { + idx, found := index[a.Key] + if found { + dropped++ + unique[idx] = a + } else { + unique = append(unique, a) + index[a.Key] = len(unique) - 1 + } + } + return unique, dropped +} + +func (r *Record) setAttributes(attrs []log.KeyValue) { r.nFront = 0 var i int for i = 0; i < len(attrs) && r.nFront < len(r.front); i++ { @@ -160,6 +273,12 @@ func (r *Record) AttributesLen() int { return r.nFront + len(r.back) } +// DroppedAttributes returns the number of attributes dropped due to limits +// being reached. +func (r *Record) DroppedAttributes() int { + return r.dropped +} + // TraceID returns the trace ID or empty array. func (r *Record) TraceID() trace.TraceID { return r.traceID @@ -206,26 +325,6 @@ func (r *Record) InstrumentationScope() instrumentation.Scope { return *r.scope } -// AttributeValueLengthLimit is the maximum allowed attribute value length. -// -// This limit only applies to string and string slice attribute values. -// Any string longer than this value should be truncated to this length. -// -// Negative value means no limit should be applied. -func (r *Record) AttributeValueLengthLimit() int { - return r.attributeValueLengthLimit -} - -// AttributeCountLimit is the maximum allowed log record attribute count. Any -// attribute added to a log record once this limit is reached should be dropped. -// -// Zero means no attributes should be recorded. -// -// Negative value means no limit should be applied. -func (r *Record) AttributeCountLimit() int { - return r.attributeCountLimit -} - // Clone returns a copy of the record with no shared state. The original record // and the clone can both be modified without interfering with each other. func (r *Record) Clone() Record { diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 0ccdfea0787..3aef28d68c2 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -125,20 +125,6 @@ func TestRecordInstrumentationScope(t *testing.T) { assert.Equal(t, scope, r.InstrumentationScope()) } -func TestRecordAttributeValueLengthLimit(t *testing.T) { - limit := 12 - r := new(Record) - r.attributeValueLengthLimit = limit - assert.Equal(t, limit, r.AttributeValueLengthLimit()) -} - -func TestRecordAttributeCountLimit(t *testing.T) { - limit := 21 - r := new(Record) - r.attributeCountLimit = limit - assert.Equal(t, limit, r.AttributeCountLimit()) -} - func TestRecordClone(t *testing.T) { now0 := time.Now() sev0 := log.SeverityInfo From 934690f914202dc655103499c4a87a8117fe7d98 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 11:18:56 -0700 Subject: [PATCH 02/13] Add changelog entry --- CHANGELOG.md | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 56a8a2e4448..1052aa8378b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,10 +8,20 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ## [Unreleased] +### Added + +- The `DroppedAttributes` is added to the `"go.opentelemetry.io/otel/sdk/log".Record` type. + This method can be used to determine how many log attributes were dropped from the `Record` due to limits being exceeded. (#TBD) + ### Changed - Update `go.opentelemetry.io/proto/otlp` from v1.1.0 to v1.2.0. (#5177) +### Removed + +- The `AttributeCountLimit` on the `"go.opentelemetry.io/otel/sdk/log".Record` type is removed. (#TBD) +- The `AttributeValueLengthLimit` on the `"go.opentelemetry.io/otel/sdk/log".Record` type is removed. (#TBD) + ## [1.25.0/0.47.0/0.0.8/0.1.0-alpha] 2024-04-05 ### Added From 46e4577c77f5c4c548b0d41adc7e8979414f1217 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 11:55:35 -0700 Subject: [PATCH 03/13] Add TestRecordDroppedAttributes --- sdk/log/record_test.go | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 3aef28d68c2..8d1afe18512 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -190,3 +190,18 @@ func TestRecordClone(t *testing.T) { return assert.Truef(t, kv.Equal(attr1), "%v != %v", kv, attr1) }) } + +func TestRecordDroppedAttributes(t *testing.T) { + for i := 1; i < attributesInlineCount*5; i++ { + r := new(Record) + r.attributeCountLimit = 1 + + attrs := make([]log.KeyValue, i) + attrs[0] = log.Bool("only key different then the rest", true) + r.AddAttributes(attrs...) + assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: AddAttributes", i) + + r.SetAttributes(attrs...) + assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: SetAttributes", i) + } +} From 3093a6e232ed7c8bbbab166ce80c8698a748651e Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 12:48:07 -0700 Subject: [PATCH 04/13] Add TestRecordCompactAttr --- sdk/log/record.go | 12 +++-- sdk/log/record_test.go | 101 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 108 insertions(+), 5 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 395e678b9ce..b53a5182f5e 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -188,6 +188,7 @@ func (r *Record) compactAttr() { } r.nFront -= dropped + // Compact back storage into front. for cursor < attributesInlineCount && len(r.back) > 0 { key := r.back[0].Key idx, found := index[key] @@ -204,19 +205,20 @@ func (r *Record) compactAttr() { r.back = r.back[1:] } - for i, a := range r.back { - key := a.Key + for i := 0; i < len(r.back); i++ { + key := r.back[i].Key idx, found := index[key] if found { dropped++ if idx < 0 { - r.front[-(idx + 1)] = a + r.front[-(idx + 1)] = r.back[i] } else { - r.back[idx] = a // stored in back: positive index. + r.back[idx] = r.back[i] } r.back = append(r.back[:i], r.back[i+1:]...) + i-- } else { - index[key] = i + index[key] = i // stored in back: positive index. } } diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 8d1afe18512..ccaae50e884 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -4,6 +4,7 @@ package log import ( + "strconv" "testing" "time" @@ -205,3 +206,103 @@ func TestRecordDroppedAttributes(t *testing.T) { assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: SetAttributes", i) } } + +func TestRecordCompactAttr(t *testing.T) { + testcases := []struct { + name string + attrs []log.KeyValue + want []log.KeyValue + }{ + { + name: "EmptyKey", + attrs: make([]log.KeyValue, 10), + want: make([]log.KeyValue, 1), + }, + { + name: "NonEmptyKey", + attrs: []log.KeyValue{ + log.Bool("key", true), + log.Int64("key", 1), + log.Bool("key", false), + log.Float64("key", 2.), + log.String("key", "3"), + log.Slice("key", log.Int64Value(4)), + log.Map("key", log.Int("key", 5)), + log.Bytes("key", []byte("six")), + log.Bool("key", false), + }, + want: []log.KeyValue{ + log.Bool("key", false), + }, + }, + { + name: "Multiple", + attrs: []log.KeyValue{ + log.Bool("a", true), + log.Int64("b", 1), + log.Bool("a", false), + log.Float64("c", 2.), + log.String("b", "3"), + log.Slice("d", log.Int64Value(4)), + log.Map("a", log.Int("key", 5)), + log.Bytes("d", []byte("six")), + log.Bool("e", true), + log.Int("f", 1), + log.Int("f", 2), + log.Int("f", 3), + log.Float64("b", 0.0), + log.Float64("b", 0.0), + log.String("g", "G"), + log.String("h", "H"), + log.String("g", "GG"), + log.Bool("a", false), + }, + want: []log.KeyValue{ + // Order is important here. + log.Bool("a", false), + log.Float64("b", 0.0), + log.Float64("c", 2.), + log.Bytes("d", []byte("six")), + log.Bool("e", true), + log.Int("f", 3), + log.String("g", "GG"), + log.String("h", "H"), + }, + }, + { + name: "NoDuplicate", + attrs: func() []log.KeyValue { + out := make([]log.KeyValue, attributesInlineCount*2) + for i := range out { + out[i] = log.Bool(strconv.Itoa(i), true) + } + return out + }(), + want: func() []log.KeyValue { + out := make([]log.KeyValue, attributesInlineCount*2) + for i := range out { + out[i] = log.Bool(strconv.Itoa(i), true) + } + return out + }(), + }, + } + + for _, tc := range testcases { + t.Run(tc.name, func(t *testing.T) { + r := new(Record) + r.setAttributes(tc.attrs) + r.compactAttr() + + var i int + r.WalkAttributes(func(kv log.KeyValue) bool { + if assert.Lessf(t, i, len(tc.want), "additional: %v", kv) { + want := tc.want[i] + assert.Truef(t, kv.Equal(want), "%d: want %v, got %v", i, want, kv) + } + i++ + return true + }) + }) + } +} From 2edc1ce21766c4bc580485ea8dcc958ccc534426 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 12:54:17 -0700 Subject: [PATCH 05/13] Add an indexPool --- sdk/log/record.go | 25 ++++++++++++++++++++++--- 1 file changed, 22 insertions(+), 3 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index b53a5182f5e..4602279a8e8 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -5,6 +5,7 @@ package log // import "go.opentelemetry.io/otel/sdk/log" import ( "slices" + "sync" "time" "go.opentelemetry.io/otel/log" @@ -19,6 +20,20 @@ import ( // cover 95% of all use-cases (https://go.dev/blog/slog#performance). const attributesInlineCount = 5 +// indexPool is a pool of index maps used for de-duplication. +var indexPool = sync.Pool{ + New: func() any { return make(map[string]int) }, +} + +func getIndex() map[string]int { + return indexPool.Get().(map[string]int) +} + +func putIndex(index map[string]int) { + clear(index) + indexPool.Put(index) +} + // Record is a log record emitted by the Logger. type Record struct { // Do not embed the log.Record. Attributes need to be overwrite-able and @@ -167,12 +182,14 @@ func (r *Record) addAttributes(attrs []log.KeyValue) { } func (r *Record) compactAttr() { - var dropped int // index holds the location of attributes in the record based on the // attribute key. If the value stored is < 0 the -(value + 1) (e.g. -1 -> // 0, -2 -> 1, -3 -> 2) represents the index in r.nFront. Otherwise, the // index is exact index of r.back. - index := make(map[string]int) + index := getIndex() + defer putIndex(index) + + var dropped int var cursor int for i := 0; i < r.nFront; i++ { key := r.front[i].Key @@ -244,7 +261,9 @@ func (r *Record) SetAttributes(attrs ...log.KeyValue) { func deduplicate(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { unique = kvs[:0] - index := make(map[string]int) + index := getIndex() + defer putIndex(index) + for _, a := range kvs { idx, found := index[a.Key] if found { From 312bc67573d03c79dd3efae7c759d9d7f18e8fba Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Wed, 10 Apr 2024 12:55:08 -0700 Subject: [PATCH 06/13] Fix gramatical error --- sdk/log/record.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 4602279a8e8..714115a3e63 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -185,7 +185,7 @@ func (r *Record) compactAttr() { // index holds the location of attributes in the record based on the // attribute key. If the value stored is < 0 the -(value + 1) (e.g. -1 -> // 0, -2 -> 1, -3 -> 2) represents the index in r.nFront. Otherwise, the - // index is exact index of r.back. + // index is the exact index of r.back. index := getIndex() defer putIndex(index) From cbc5417b6fd789af376d8d684cc8c8a5460b321a Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Fri, 12 Apr 2024 07:19:17 -0700 Subject: [PATCH 07/13] Apply feedback Reduce indentation level. --- sdk/log/record.go | 24 +++++++++++------------- 1 file changed, 11 insertions(+), 13 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 714115a3e63..b473398899e 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -150,19 +150,17 @@ func (r *Record) WalkAttributes(f func(log.KeyValue) bool) { // AddAttributes adds attributes to the log record. func (r *Record) AddAttributes(attrs ...log.KeyValue) { - if r.attributeCountLimit > 0 { - if r.AttributesLen()+len(attrs) > r.attributeCountLimit { - r.compactAttr() - // TODO: apply truncation to string and []string values. - var dropped int - attrs, dropped = deduplicate(attrs) - r.dropped += dropped - - if n := r.AttributesLen(); n+len(attrs) > r.attributeCountLimit { - last := max(0, (r.attributeCountLimit - n)) - r.dropped += len(attrs) - last - attrs = attrs[:last] - } + if r.attributeCountLimit > 0 && r.AttributesLen()+len(attrs) > r.attributeCountLimit { + r.compactAttr() + // TODO: apply truncation to string and []string values. + var dropped int + attrs, dropped = deduplicate(attrs) + r.dropped += dropped + + if n := r.AttributesLen(); n+len(attrs) > r.attributeCountLimit { + last := max(0, (r.attributeCountLimit - n)) + r.dropped += len(attrs) - last + attrs = attrs[:last] } } From e55c7b1bec183d95f3c3668bf37d666c392b753e Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Fri, 12 Apr 2024 07:25:46 -0700 Subject: [PATCH 08/13] Apply feedback Comment compactAttr and deduplicate. --- sdk/log/record.go | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/sdk/log/record.go b/sdk/log/record.go index b473398899e..9af47c0a8e2 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -179,6 +179,10 @@ func (r *Record) addAttributes(attrs []log.KeyValue) { r.back = append(r.back, attrs[i:]...) } +// compactAttr deduplicates and compacts r's attributes. Attributes are +// deduplicated front-to-back with the last value saved. Any space in the front +// storage freed during deduplication will populated by attributes from the +// back storage in order. func (r *Record) compactAttr() { // index holds the location of attributes in the record based on the // attribute key. If the value stored is < 0 the -(value + 1) (e.g. -1 -> @@ -256,6 +260,7 @@ func (r *Record) SetAttributes(attrs ...log.KeyValue) { r.setAttributes(attrs) } +// deduplicate deduplicates kvs front-to-back with the last value saved. func deduplicate(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { unique = kvs[:0] From 91ed94df91fc29cac5dd8ee9810e03b87b34473a Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Mon, 15 Apr 2024 12:55:39 -0700 Subject: [PATCH 09/13] Deduplicate all attributes when added --- sdk/log/record.go | 201 +++++++++++++++++++++-------------------- sdk/log/record_test.go | 48 +++++++--- 2 files changed, 137 insertions(+), 112 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 9af47c0a8e2..63a99878fd5 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -150,123 +150,138 @@ func (r *Record) WalkAttributes(f func(log.KeyValue) bool) { // AddAttributes adds attributes to the log record. func (r *Record) AddAttributes(attrs ...log.KeyValue) { - if r.attributeCountLimit > 0 && r.AttributesLen()+len(attrs) > r.attributeCountLimit { - r.compactAttr() - // TODO: apply truncation to string and []string values. - var dropped int - attrs, dropped = deduplicate(attrs) - r.dropped += dropped - - if n := r.AttributesLen(); n+len(attrs) > r.attributeCountLimit { - last := max(0, (r.attributeCountLimit - n)) - r.dropped += len(attrs) - last - attrs = attrs[:last] - } - } + n := r.AttributesLen() + if n == 0 { + // Avoid the more complex duplicate map lookups bellow. + attrs, r.dropped = dedup(attrs) - r.addAttributes(attrs) -} + var drop int + attrs, drop = head(attrs, r.attributeCountLimit) + r.dropped += drop -func (r *Record) addAttributes(attrs []log.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.addAttrs(attrs) + return } - r.back = slices.Grow(r.back, len(attrs[i:])) - r.back = append(r.back, attrs[i:]...) -} + // Deduplicate attrs within the scope of all existing attributes. -// compactAttr deduplicates and compacts r's attributes. Attributes are -// deduplicated front-to-back with the last value saved. Any space in the front -// storage freed during deduplication will populated by attributes from the -// back storage in order. -func (r *Record) compactAttr() { - // index holds the location of attributes in the record based on the - // attribute key. If the value stored is < 0 the -(value + 1) (e.g. -1 -> - // 0, -2 -> 1, -3 -> 2) represents the index in r.nFront. Otherwise, the - // index is the exact index of r.back. - index := getIndex() - defer putIndex(index) + rIndex := r.attrIndex() + defer putIndex(rIndex) - var dropped int - var cursor int - for i := 0; i < r.nFront; i++ { - key := r.front[i].Key - idx, found := index[key] - if found { - dropped++ - r.front[-(idx + 1)] = r.front[i] - } else { - r.front[cursor] = r.front[i] - index[key] = -cursor - 1 // stored in front: negative index. - cursor++ - } - } - r.nFront -= dropped + // Unique attrs that need to be added to r. + // + // Note, do not iterate attrs twice by just calling dedup(attrs) here. + unique := attrs[:0] + uIndex := getIndex() + defer putIndex(uIndex) - // Compact back storage into front. - for cursor < attributesInlineCount && len(r.back) > 0 { - key := r.back[0].Key - idx, found := index[key] + for _, a := range attrs { + // Last-value-wins for any duplicates in attrs. + idx, found := uIndex[a.Key] if found { - dropped++ - r.front[-(idx + 1)] = r.back[0] - } else { - r.front[cursor] = r.back[0] - r.nFront++ - - index[key] = -cursor - 1 // stored in front: negative index. - cursor++ + r.dropped++ + unique[idx] = a + continue } - r.back = r.back[1:] - } - for i := 0; i < len(r.back); i++ { - key := r.back[i].Key - idx, found := index[key] + idx, found = rIndex[a.Key] if found { - dropped++ + // New attrs overwrite any existing with the same key. + r.dropped++ if idx < 0 { - r.front[-(idx + 1)] = r.back[i] + r.front[-(idx + 1)] = a } else { - r.back[idx] = r.back[i] + r.back[idx] = a } - r.back = append(r.back[:i], r.back[i+1:]...) - i-- } else { - index[key] = i // stored in back: positive index. + // Unique attribute. + // TODO: apply truncation to string and []string values. + unique = append(unique, a) + uIndex[a.Key] = len(unique) - 1 } } + attrs = unique + + if r.attributeCountLimit > 0 && n+len(attrs) > r.attributeCountLimit { + // Truncate the now unique attributes to comply with limit. + last := max(0, (r.attributeCountLimit - n)) + r.dropped += len(attrs) - last + attrs = attrs[:last] + } + + r.addAttrs(attrs) +} + +// attrIndex returns an index map for all attributes in the Record r. The index +// maps the attribute key to location the attribute is stored. If the value is +// < 0 then -(value + 1) (e.g. -1 -> 0, -2 -> 1, -3 -> 2) represents the index +// in r.nFront. Otherwise, the index is the exact index of r.back. +// +// The returned index is taken from the indexPool. It is the callers +// responsibility to return the index to that pool (putIndex) when done. +func (r *Record) attrIndex() map[string]int { + index := getIndex() + for i := 0; i < r.nFront; i++ { + key := r.front[i].Key + index[key] = -i - 1 // stored in front: negative index. + } + for i := 0; i < len(r.back); i++ { + key := r.back[i].Key + index[key] = i // stored in back: positive index. + } + return index +} - r.dropped += dropped +// addAttrs adds attrs to the Record r. This does not validate any limits or +// duplication of attributes, these tasks are left to the caller to handle +// prior to calling. +func (r *Record) addAttrs(attrs []log.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:]...) } // SetAttributes sets (and overrides) attributes to the log record. func (r *Record) SetAttributes(attrs ...log.KeyValue) { - // If adding these attributes could exceed limit, de-duplicate to minimize - // overflow. - if r.attributeCountLimit > 0 && len(attrs) > r.attributeCountLimit { - // TODO: apply truncation to string and []string values. - attrs, r.dropped = deduplicate(attrs) - if len(attrs) > r.attributeCountLimit { - r.dropped += len(attrs) - r.attributeCountLimit - attrs = attrs[:r.attributeCountLimit] - } + // TODO: apply truncation to string and []string values. + attrs, r.dropped = dedup(attrs) + + var drop int + attrs, drop = head(attrs, r.attributeCountLimit) + r.dropped += drop + + r.nFront = 0 + 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.setAttributes(attrs) + r.back = slices.Clone(attrs[i:]) } -// deduplicate deduplicates kvs front-to-back with the last value saved. -func deduplicate(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { - unique = kvs[:0] +// head returns the first n values of kvs along with the number of elements +// dropped. If n is less than or equal to zero, kvs is returned with 0. +func head(kvs []log.KeyValue, n int) (out []log.KeyValue, dropped int) { + if n > 0 && len(kvs) > n { + return kvs[:n], len(kvs) - n + } + return kvs, 0 +} +// dedup deduplicates kvs front-to-back with the last value saved. +func dedup(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { index := getIndex() defer putIndex(index) + unique = kvs[:0] // Use the same underlying array as kvs. for _, a := range kvs { idx, found := index[a.Key] if found { @@ -280,18 +295,6 @@ func deduplicate(kvs []log.KeyValue) (unique []log.KeyValue, dropped int) { return unique, dropped } -func (r *Record) setAttributes(attrs []log.KeyValue) { - r.nFront = 0 - 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.Clone(attrs[i:]) -} - // AttributesLen returns the number of attributes in the log record. func (r *Record) AttributesLen() int { return r.nFront + len(r.back) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index ccaae50e884..99adfdfa9e9 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -202,12 +202,15 @@ func TestRecordDroppedAttributes(t *testing.T) { r.AddAttributes(attrs...) assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: AddAttributes", i) + r.AddAttributes(attrs...) + assert.Equalf(t, 2*i-1, r.DroppedAttributes(), "%d: second AddAttributes", i) + r.SetAttributes(attrs...) assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: SetAttributes", i) } } -func TestRecordCompactAttr(t *testing.T) { +func TestRecordAttrDeduplication(t *testing.T) { testcases := []struct { name string attrs []log.KeyValue @@ -290,18 +293,37 @@ func TestRecordCompactAttr(t *testing.T) { for _, tc := range testcases { t.Run(tc.name, func(t *testing.T) { - r := new(Record) - r.setAttributes(tc.attrs) - r.compactAttr() - - var i int - r.WalkAttributes(func(kv log.KeyValue) bool { - if assert.Lessf(t, i, len(tc.want), "additional: %v", kv) { - want := tc.want[i] - assert.Truef(t, kv.Equal(want), "%d: want %v, got %v", i, want, kv) - } - i++ - return true + validate := func(t *testing.T, r *Record) { + t.Helper() + + var i int + r.WalkAttributes(func(kv log.KeyValue) bool { + if assert.Lessf(t, i, len(tc.want), "additional: %v", kv) { + want := tc.want[i] + assert.Truef(t, kv.Equal(want), "%d: want %v, got %v", i, want, kv) + } + i++ + return true + }) + } + + t.Run("SetAttributes", func(t *testing.T) { + r := new(Record) + r.SetAttributes(tc.attrs...) + validate(t, r) + }) + + t.Run("AddAttributes/Empty", func(t *testing.T) { + r := new(Record) + r.AddAttributes(tc.attrs...) + validate(t, r) + }) + + t.Run("AddAttributes/Duplicates", func(t *testing.T) { + r := new(Record) + r.AddAttributes(tc.attrs...) + r.AddAttributes(tc.attrs...) + validate(t, r) }) }) } From bb1474bfa851dad9233786b7ea968b86f865039a Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Mon, 15 Apr 2024 13:09:43 -0700 Subject: [PATCH 10/13] Comment why head is not used --- sdk/log/record.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/sdk/log/record.go b/sdk/log/record.go index 63a99878fd5..360a474c419 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -204,6 +204,9 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) { if r.attributeCountLimit > 0 && n+len(attrs) > r.attributeCountLimit { // Truncate the now unique attributes to comply with limit. + // + // Do not use head(attrs, r.attributeCountLimit - n) here. If + // (r.attributeCountLimit - n) <= 0 attrs needs to be emptied. last := max(0, (r.attributeCountLimit - n)) r.dropped += len(attrs) - last attrs = attrs[:last] From e18f333bf411fbefe142f16658dc68cf32c23a28 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Mon, 15 Apr 2024 13:19:38 -0700 Subject: [PATCH 11/13] Clarify comments --- sdk/log/record.go | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 360a474c419..cffdeb1c27e 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -163,18 +163,21 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) { return } - // Deduplicate attrs within the scope of all existing attributes. - + // Used to find duplicates between attrs and existing attributes in r. rIndex := r.attrIndex() defer putIndex(rIndex) - // Unique attrs that need to be added to r. + // Unique attrs that need to be added to r. This uses the same underlying + // array as attrs. // // Note, do not iterate attrs twice by just calling dedup(attrs) here. unique := attrs[:0] + // Used to find duplicates within attrs itself. The index value is the + // index of the element in unique. uIndex := getIndex() defer putIndex(uIndex) + // Deduplicate attrs within the scope of all existing attributes. for _, a := range attrs { // Last-value-wins for any duplicates in attrs. idx, found := uIndex[a.Key] From fab66bce598d3922e7204aa3ebcb4e72d0fb3e75 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Mon, 15 Apr 2024 13:27:55 -0700 Subject: [PATCH 12/13] Move TestAllocationLimits to new file Do not run this test when the race detector is on. --- sdk/log/logger_norace_test.go | 46 +++++++++++++++++++++++++++++++++++ sdk/log/logger_test.go | 25 ------------------- 2 files changed, 46 insertions(+), 25 deletions(-) create mode 100644 sdk/log/logger_norace_test.go diff --git a/sdk/log/logger_norace_test.go b/sdk/log/logger_norace_test.go new file mode 100644 index 00000000000..a7a9aaebdb9 --- /dev/null +++ b/sdk/log/logger_norace_test.go @@ -0,0 +1,46 @@ +// Copyright The OpenTelemetry Authors +// SPDX-License-Identifier: Apache-2.0 + +//go:build !race + +package log + +import ( + "context" + "testing" + "time" + + "github.com/stretchr/testify/assert" + + "go.opentelemetry.io/otel/log" + "go.opentelemetry.io/otel/sdk/instrumentation" +) + +func TestAllocationLimits(t *testing.T) { + // This test is not run with a race detector. The sync.Pool used by parts + // of the SDK has memory optimizations removed for the race detector. Do + // not test performance of the SDK in that state. + + const runs = 10 + + logger := newLogger(NewLoggerProvider(), instrumentation.Scope{}) + + r := log.Record{} + r.SetTimestamp(time.Date(2000, time.January, 1, 0, 0, 0, 0, time.UTC)) + r.SetObservedTimestamp(time.Date(2000, time.January, 1, 0, 0, 0, 0, time.UTC)) + r.SetBody(log.StringValue("testing body value")) + r.SetSeverity(log.SeverityInfo) + r.SetSeverityText("testing text") + + r.AddAttributes( + log.String("k1", "str"), + log.Float64("k2", 1.0), + log.Int("k3", 2), + log.Bool("k4", true), + log.Bytes("k5", []byte{1}), + ) + + assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { + logger.newRecord(context.Background(), r) + }), "newRecord") +} diff --git a/sdk/log/logger_test.go b/sdk/log/logger_test.go index b966f7614f3..6443bf77d71 100644 --- a/sdk/log/logger_test.go +++ b/sdk/log/logger_test.go @@ -273,28 +273,3 @@ func TestLoggerEnabled(t *testing.T) { }) } } - -func TestAllocationLimits(t *testing.T) { - const runs = 10 - - logger := newLogger(NewLoggerProvider(), instrumentation.Scope{}) - - r := log.Record{} - r.SetTimestamp(time.Date(2000, time.January, 1, 0, 0, 0, 0, time.UTC)) - r.SetObservedTimestamp(time.Date(2000, time.January, 1, 0, 0, 0, 0, time.UTC)) - r.SetBody(log.StringValue("testing body value")) - r.SetSeverity(log.SeverityInfo) - r.SetSeverityText("testing text") - - r.AddAttributes( - log.String("k1", "str"), - log.Float64("k2", 1.0), - log.Int("k3", 2), - log.Bool("k4", true), - log.Bytes("k5", []byte{1}), - ) - - assert.Equal(t, 0.0, testing.AllocsPerRun(runs, func() { - logger.newRecord(context.Background(), r) - }), "newRecord") -} From 9c3e01b965fe7f36a4dd450be3d785f161a054fd Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Tue, 16 Apr 2024 07:29:12 -0700 Subject: [PATCH 13/13] Comment follow-up task --- sdk/log/record.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/sdk/log/record.go b/sdk/log/record.go index cffdeb1c27e..74ae2888e74 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -199,6 +199,7 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) { } else { // Unique attribute. // TODO: apply truncation to string and []string values. + // TODO: deduplicate map values. unique = append(unique, a) uIndex[a.Key] = len(unique) - 1 } @@ -256,6 +257,7 @@ func (r *Record) addAttrs(attrs []log.KeyValue) { // SetAttributes sets (and overrides) attributes to the log record. func (r *Record) SetAttributes(attrs ...log.KeyValue) { // TODO: apply truncation to string and []string values. + // TODO: deduplicate map values. attrs, r.dropped = dedup(attrs) var drop int