From ee35e1441ec9a6130013edcc9e9d20d2834c2e89 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 13:47:03 +0100 Subject: [PATCH 01/13] add test cases for keyvalue collections with duplicates in log body --- sdk/log/record_test.go | 66 +++++++++++++++++++++++++++++++++++++++--- 1 file changed, 62 insertions(+), 4 deletions(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 8132dc59585..ea93dbe7490 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -56,10 +56,68 @@ func TestRecordSeverityText(t *testing.T) { } func TestRecordBody(t *testing.T) { - v := log.BoolValue(true) - r := new(Record) - r.SetBody(v) - assert.True(t, v.Equal(r.Body())) + testcases := []struct { + name string + body log.Value + want log.Value + }{ + { + name: "Bool", + body: log.BoolValue(true), + want: log.BoolValue(true), + }, + { + name: "slice", + body: log.SliceValue(log.BoolValue(true), log.BoolValue(false)), + want: log.SliceValue(log.BoolValue(true), log.BoolValue(false)), + }, + { + name: "map", + body: log.MapValue( + log.Bool("0", true), + log.Int64("1", 2), // This should be removed + log.Float64("2", 3.0), + log.String("3", "forth"), + log.Slice("4", log.Int64Value(1)), + log.Map("5", log.Int("key", 2)), + log.Bytes("6", []byte("six")), + log.Int64("1", 3), + ), + want: log.MapValue( + log.Bool("0", true), + log.Float64("2", 3.0), + log.String("3", "forth"), + log.Slice("4", log.Int64Value(1)), + log.Map("5", log.Int("key", 2)), + log.Bytes("6", []byte("six")), + log.Int64("1", 3), + ), + }, + { + name: "nestedMap", + body: log.MapValue( + log.Map("key", + log.Int64("key", 1), + log.Int64("key", 2), + ), + ), + want: log.MapValue( + log.Map("key", + log.Int64("key", 2), + ), + ), + }, + } + for _, tc := range testcases { + t.Run(tc.name, func(t *testing.T) { + r := new(Record) + r.SetBody(tc.body) + assert.True(t, tc.want.Equal(r.Body()), "body is not equal") + t.Logf("wanted %v", tc.want) + t.Logf("got %v", r.Body()) + }) + } + } func TestRecordAttributes(t *testing.T) { From 6d291b231698d25c70fe7197348ea33c6251677e Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 13:47:29 +0100 Subject: [PATCH 02/13] update SetBody to deduplicate keyvalue collections --- sdk/log/record.go | 22 +++++++++++++--------- 1 file changed, 13 insertions(+), 9 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 3f6fec5f375..a8225477063 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -170,7 +170,7 @@ func (r *Record) Body() log.Value { // SetBody sets the body of the log record. func (r *Record) SetBody(v log.Value) { - r.body = v + r.body = r.dedupeAndApplyValueLimits(v, false, false) // We don't want to limit the body nor track any duplicate dropped } // WalkAttributes walks all attributes the log record holds by calling f for @@ -418,21 +418,23 @@ func (r *Record) Clone() Record { } func (r *Record) applyAttrLimits(attr log.KeyValue) log.KeyValue { - attr.Value = r.applyValueLimits(attr.Value) + attr.Value = r.dedupeAndApplyValueLimits(attr.Value, true, true) return attr } -func (r *Record) applyValueLimits(val log.Value) log.Value { +func (r *Record) dedupeAndApplyValueLimits(val log.Value, applyLimits, trackDropped bool) log.Value { switch val.Kind() { case log.KindString: - s := val.AsString() - if len(s) > r.attributeValueLengthLimit { - val = log.StringValue(truncate(r.attributeValueLengthLimit, s)) + if applyLimits { + s := val.AsString() + if r.attributeValueLengthLimit > 0 && len(s) > r.attributeValueLengthLimit { + val = log.StringValue(truncate(r.attributeValueLengthLimit, s)) + } } case log.KindSlice: sl := val.AsSlice() for i := range sl { - sl[i] = r.applyValueLimits(sl[i]) + sl[i] = r.dedupeAndApplyValueLimits(sl[i], applyLimits, trackDropped) } val = log.SliceValue(sl...) case log.KindMap: @@ -442,10 +444,12 @@ func (r *Record) applyValueLimits(val log.Value) log.Value { // wasted truncation operations. var dropped int kvs, dropped = dedup(kvs) - r.addDropped(dropped) + if trackDropped { + r.addDropped(dropped) + } } for i := range kvs { - kvs[i] = r.applyAttrLimits(kvs[i]) + kvs[i].Value = r.dedupeAndApplyValueLimits(kvs[i].Value, applyLimits, trackDropped) } val = log.MapValue(kvs...) } From 642daca1ffdd037111a931aa9776f3fdb1d4dbfb Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 13:57:10 +0100 Subject: [PATCH 03/13] refactor dedupeandlimit func into separate funcs --- sdk/log/record.go | 42 +++++++++++++++++++++++++++++------------- 1 file changed, 29 insertions(+), 13 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index a8225477063..1870101347e 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -170,7 +170,9 @@ func (r *Record) Body() log.Value { // SetBody sets the body of the log record. func (r *Record) SetBody(v log.Value) { - r.body = r.dedupeAndApplyValueLimits(v, false, false) // We don't want to limit the body nor track any duplicate dropped + if !r.allowDupKeys { + r.body = r.dedupeBodyCollections(v) + } } // WalkAttributes walks all attributes the log record holds by calling f for @@ -418,23 +420,21 @@ func (r *Record) Clone() Record { } func (r *Record) applyAttrLimits(attr log.KeyValue) log.KeyValue { - attr.Value = r.dedupeAndApplyValueLimits(attr.Value, true, true) + attr.Value = r.applyValueLimits(attr.Value) return attr } -func (r *Record) dedupeAndApplyValueLimits(val log.Value, applyLimits, trackDropped bool) log.Value { +func (r *Record) applyValueLimits(val log.Value) log.Value { switch val.Kind() { case log.KindString: - if applyLimits { - s := val.AsString() - if r.attributeValueLengthLimit > 0 && len(s) > r.attributeValueLengthLimit { - val = log.StringValue(truncate(r.attributeValueLengthLimit, s)) - } + s := val.AsString() + if len(s) > r.attributeValueLengthLimit { + val = log.StringValue(truncate(r.attributeValueLengthLimit, s)) } case log.KindSlice: sl := val.AsSlice() for i := range sl { - sl[i] = r.dedupeAndApplyValueLimits(sl[i], applyLimits, trackDropped) + sl[i] = r.applyValueLimits(sl[i]) } val = log.SliceValue(sl...) case log.KindMap: @@ -444,12 +444,28 @@ func (r *Record) dedupeAndApplyValueLimits(val log.Value, applyLimits, trackDrop // wasted truncation operations. var dropped int kvs, dropped = dedup(kvs) - if trackDropped { - r.addDropped(dropped) - } + r.addDropped(dropped) + } + for i := range kvs { + kvs[i] = r.applyAttrLimits(kvs[i]) + } + val = log.MapValue(kvs...) + } + return val +} + +func (r *Record) dedupeBodyCollections(val log.Value) log.Value { + switch val.Kind() { + case log.KindSlice: + sl := val.AsSlice() + for i := range sl { + sl[i] = r.applyValueLimits(sl[i]) } + val = log.SliceValue(sl...) + case log.KindMap: + kvs, _ := dedup(val.AsMap()) for i := range kvs { - kvs[i].Value = r.dedupeAndApplyValueLimits(kvs[i].Value, applyLimits, trackDropped) + kvs[i].Value = r.dedupeBodyCollections(kvs[i].Value) } val = log.MapValue(kvs...) } From d09263a2fc7715ec28f630cba155d966a9832d5b Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 13:57:19 +0100 Subject: [PATCH 04/13] lint --- sdk/log/record_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index ea93dbe7490..7129c21048c 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -117,7 +117,6 @@ func TestRecordBody(t *testing.T) { t.Logf("got %v", r.Body()) }) } - } func TestRecordAttributes(t *testing.T) { From 319c0869baa6484193e8b343678f808107277abd Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 14:10:12 +0100 Subject: [PATCH 05/13] fix allowDuplicates bug and add test --- sdk/log/record.go | 2 ++ sdk/log/record_test.go | 20 +++++++++++++++++--- 2 files changed, 19 insertions(+), 3 deletions(-) diff --git a/sdk/log/record.go b/sdk/log/record.go index 1870101347e..c08d9bfb274 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -172,6 +172,8 @@ func (r *Record) Body() log.Value { func (r *Record) SetBody(v log.Value) { if !r.allowDupKeys { r.body = r.dedupeBodyCollections(v) + } else { + r.body = v } } diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 7129c21048c..e26a2ca5e7c 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -57,9 +57,10 @@ func TestRecordSeverityText(t *testing.T) { func TestRecordBody(t *testing.T) { testcases := []struct { - name string - body log.Value - want log.Value + name string + body log.Value + want log.Value + allowDuplicates bool }{ { name: "Bool", @@ -107,10 +108,23 @@ func TestRecordBody(t *testing.T) { ), ), }, + { + name: "map - allow duplicates", + body: log.MapValue( + log.Int64("1", 2), + log.Int64("1", 3), + ), + want: log.MapValue( + log.Int64("1", 2), + log.Int64("1", 3), + ), + allowDuplicates: true, + }, } for _, tc := range testcases { t.Run(tc.name, func(t *testing.T) { r := new(Record) + r.allowDupKeys = tc.allowDuplicates r.SetBody(tc.body) assert.True(t, tc.want.Equal(r.Body()), "body is not equal") t.Logf("wanted %v", tc.want) From 07d610f8c03a764cac1cb82c535198d875437504 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Mon, 14 Jul 2025 14:17:28 +0100 Subject: [PATCH 06/13] changelog --- CHANGELOG.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 64d910962b7..4bef749c00a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -49,6 +49,10 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm +### Fixes + +- sdk/log: Deduplicate key-value collections in log body in `go.opentelemetry.io/otel/sdk/log`, as per OTel spec. (#7002) + ## [1.37.0/0.59.0/0.13.0] 2025-06-25 ### Added From 3e64aa9a92af8aeb572be0c9a547ac06188ce2d2 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Tue, 15 Jul 2025 09:25:49 +0100 Subject: [PATCH 07/13] fix dedupe body using wrong function, update changelog --- CHANGELOG.md | 6 ++++-- sdk/log/record.go | 2 +- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4bef749c00a..6c66acfadb8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -46,12 +46,14 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - Change `AssertEqual` in `go.opentelemetry.io/otel/log/logtest` to accept `TestingT` in order to support benchmarks and fuzz tests. (#6908) +### Fixes + +- `SetBody` method of `Record` in `go.opentelemetry.io/otel/sdk/log` now deduplicates key-value collections (`log.Value` of `log.KindMap` from `go.opentelemetry.io/otel/log`). (#7002) + -### Fixes -- sdk/log: Deduplicate key-value collections in log body in `go.opentelemetry.io/otel/sdk/log`, as per OTel spec. (#7002) ## [1.37.0/0.59.0/0.13.0] 2025-06-25 diff --git a/sdk/log/record.go b/sdk/log/record.go index c08d9bfb274..9dfd69b645b 100644 --- a/sdk/log/record.go +++ b/sdk/log/record.go @@ -461,7 +461,7 @@ func (r *Record) dedupeBodyCollections(val log.Value) log.Value { case log.KindSlice: sl := val.AsSlice() for i := range sl { - sl[i] = r.applyValueLimits(sl[i]) + sl[i] = r.dedupeBodyCollections(sl[i]) } val = log.SliceValue(sl...) case log.KindMap: From efc658a36793c474e6cd15550670d4411843f97e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Tue, 15 Jul 2025 10:36:49 +0200 Subject: [PATCH 08/13] Update CHANGELOG.md --- CHANGELOG.md | 2 -- 1 file changed, 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6c66acfadb8..b157253d8e7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -53,8 +53,6 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - - ## [1.37.0/0.59.0/0.13.0] 2025-06-25 ### Added From 0c54eab2c7911b9e290252502722a61c566a5350 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Tue, 15 Jul 2025 09:57:09 +0100 Subject: [PATCH 09/13] Apply suggestions from code review MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Robert Pająk --- sdk/log/record_test.go | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index e26a2ca5e7c..1719f3d5659 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -58,9 +58,9 @@ func TestRecordSeverityText(t *testing.T) { func TestRecordBody(t *testing.T) { testcases := []struct { name string + allowDuplicates bool body log.Value want log.Value - allowDuplicates bool }{ { name: "Bool", @@ -110,6 +110,7 @@ func TestRecordBody(t *testing.T) { }, { name: "map - allow duplicates", + allowDuplicates: true, body: log.MapValue( log.Int64("1", 2), log.Int64("1", 3), @@ -118,7 +119,6 @@ func TestRecordBody(t *testing.T) { log.Int64("1", 2), log.Int64("1", 3), ), - allowDuplicates: true, }, } for _, tc := range testcases { @@ -126,9 +126,10 @@ func TestRecordBody(t *testing.T) { r := new(Record) r.allowDupKeys = tc.allowDuplicates r.SetBody(tc.body) - assert.True(t, tc.want.Equal(r.Body()), "body is not equal") - t.Logf("wanted %v", tc.want) - t.Logf("got %v", r.Body()) + got := r.Body() + if !got.Equal(want) { + t.Errorf("r.Body() = %v, want %v", got, tc.want) + } }) } } From fbade7271d6b171509d3ecd8f7cc644cdc9d0212 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Robert=20Paj=C4=85k?= Date: Tue, 15 Jul 2025 11:05:32 +0200 Subject: [PATCH 10/13] Update sdk/log/record_test.go --- sdk/log/record_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 1719f3d5659..d5fddd1baf6 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -127,7 +127,7 @@ func TestRecordBody(t *testing.T) { r.allowDupKeys = tc.allowDuplicates r.SetBody(tc.body) got := r.Body() - if !got.Equal(want) { + if !got.Equal(tc.want) { t.Errorf("r.Body() = %v, want %v", got, tc.want) } }) From 80f089307fe8d9780f6f0bcb3f96f0c87412960a Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Tue, 15 Jul 2025 10:13:34 +0100 Subject: [PATCH 11/13] lint --- sdk/log/record_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index d5fddd1baf6..6efc26b6afe 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -109,7 +109,7 @@ func TestRecordBody(t *testing.T) { ), }, { - name: "map - allow duplicates", + name: "map - allow duplicates", allowDuplicates: true, body: log.MapValue( log.Int64("1", 2), From 5cddc9a69a8eb3f4c17c35c387eec517fefc8d31 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Fri, 25 Jul 2025 08:55:26 +0100 Subject: [PATCH 12/13] add benchmark for record.SetBody --- sdk/log/record_test.go | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/sdk/log/record_test.go b/sdk/log/record_test.go index 6efc26b6afe..103e673a15f 100644 --- a/sdk/log/record_test.go +++ b/sdk/log/record_test.go @@ -1023,3 +1023,23 @@ func BenchmarkSetAddAttributes(b *testing.B) { } }) } + +func BenchmarkSetBody(b *testing.B) { + b.Run("SetBody", func(b *testing.B) { + records := make([]Record, b.N) + + b.ResetTimer() + b.ReportAllocs() + for i := 0; i < b.N; i++ { + records[i].SetBody(log.MapValue( + log.Bool("0", true), + log.Float64("2", 3.0), + log.String("3", "forth"), + log.Slice("4", log.Int64Value(1)), + log.Map("5", log.Int("key", 2)), + log.Bytes("6", []byte("six")), + log.Int64("1", 3), + )) + } + }) +} From 6242fef3e0ca08568dbfa1f06581e808e8eab985 Mon Sep 17 00:00:00 2001 From: Joe Stephenson Date: Wed, 30 Jul 2025 13:06:12 +0100 Subject: [PATCH 13/13] newRecord dedupes body collections & add test --- sdk/log/logger.go | 4 ++- sdk/log/logger_test.go | 63 +++++++++++++++++++++++++++++++++++------- 2 files changed, 56 insertions(+), 11 deletions(-) diff --git a/sdk/log/logger.go b/sdk/log/logger.go index d3acd0562d6..9e6d8822757 100644 --- a/sdk/log/logger.go +++ b/sdk/log/logger.go @@ -84,7 +84,6 @@ func (l *logger) newRecord(ctx context.Context, r log.Record) Record { observedTimestamp: r.ObservedTimestamp(), severity: r.Severity(), severityText: r.SeverityText(), - body: r.Body(), traceID: sc.TraceID(), spanID: sc.SpanID(), @@ -97,6 +96,9 @@ func (l *logger) newRecord(ctx context.Context, r log.Record) Record { allowDupKeys: l.provider.allowDupKeys, } + // This ensures we deduplicate key-value collections in the log body + newRecord.SetBody(r.Body()) + // This field SHOULD be set once the event is observed by OpenTelemetry. if newRecord.observedTimestamp.IsZero() { newRecord.observedTimestamp = now() diff --git a/sdk/log/logger_test.go b/sdk/log/logger_test.go index fd5e8f73bf6..1f703d117b6 100644 --- a/sdk/log/logger_test.go +++ b/sdk/log/logger_test.go @@ -47,10 +47,20 @@ func TestLoggerEmit(t *testing.T) { rWithNoObservedTimestamp := r rWithNoObservedTimestamp.SetObservedTimestamp(time.Time{}) - rWithoutDeduplicateAttributes := r - rWithoutDeduplicateAttributes.AddAttributes( + rWithAllowKeyDuplication := r + rWithAllowKeyDuplication.AddAttributes( log.String("k1", "str1"), ) + rWithAllowKeyDuplication.SetBody(log.MapValue( + log.Int64("1", 2), + log.Int64("1", 3), + )) + + rWithDuplicatesInBody := r + rWithDuplicatesInBody.SetBody(log.MapValue( + log.Int64("1", 2), + log.Int64("1", 3), + )) contextWithSpanContext := trace.ContextWithSpanContext( context.Background(), @@ -212,7 +222,7 @@ func TestLoggerEmit(t *testing.T) { }, }, { - name: "WithoutAttributeDeduplication", + name: "WithAllowKeyDuplication", logger: newLogger(NewLoggerProvider( WithProcessor(p0), WithProcessor(p1), @@ -222,15 +232,15 @@ func TestLoggerEmit(t *testing.T) { WithAllowKeyDuplication(), ), instrumentation.Scope{Name: "scope"}), ctx: context.Background(), - record: rWithoutDeduplicateAttributes, + record: rWithAllowKeyDuplication, expectedRecords: []Record{ { - eventName: r.EventName(), - timestamp: r.Timestamp(), - body: r.Body(), - severity: r.Severity(), - severityText: r.SeverityText(), - observedTimestamp: r.ObservedTimestamp(), + eventName: rWithAllowKeyDuplication.EventName(), + timestamp: rWithAllowKeyDuplication.Timestamp(), + body: rWithAllowKeyDuplication.Body(), + severity: rWithAllowKeyDuplication.Severity(), + severityText: rWithAllowKeyDuplication.SeverityText(), + observedTimestamp: rWithAllowKeyDuplication.ObservedTimestamp(), resource: resource.NewSchemaless(attribute.String("key", "value")), attributeValueLengthLimit: 5, attributeCountLimit: 5, @@ -245,6 +255,39 @@ func TestLoggerEmit(t *testing.T) { }, }, }, + { + name: "WithDuplicatesInBody", + logger: newLogger(NewLoggerProvider( + WithProcessor(p0), + WithProcessor(p1), + WithAttributeValueLengthLimit(5), + WithAttributeCountLimit(5), + WithResource(resource.NewSchemaless(attribute.String("key", "value"))), + ), instrumentation.Scope{Name: "scope"}), + ctx: context.Background(), + record: rWithDuplicatesInBody, + expectedRecords: []Record{ + { + eventName: rWithDuplicatesInBody.EventName(), + timestamp: rWithDuplicatesInBody.Timestamp(), + body: log.MapValue( + log.Int64("1", 3), + ), + severity: rWithDuplicatesInBody.Severity(), + severityText: rWithDuplicatesInBody.SeverityText(), + observedTimestamp: rWithDuplicatesInBody.ObservedTimestamp(), + resource: resource.NewSchemaless(attribute.String("key", "value")), + attributeValueLengthLimit: 5, + attributeCountLimit: 5, + scope: &instrumentation.Scope{Name: "scope"}, + front: [attributesInlineCount]log.KeyValue{ + log.String("k1", "str"), + log.Float64("k2", 1.0), + }, + nFront: 2, + }, + }, + }, } for _, tc := range testCases {