Skip to content

Commit a8e1500

Browse files
Mojachieeepellared
Mojachieee
and
pellared
authored
sdk/log: Deduplicate key-value collections in Record.SetBody (#7002)
Fixes #6982 ``` goos: darwin goarch: arm64 pkg: go.opentelemetry.io/otel/sdk/log cpu: Apple M2 Pro │ old.txt │ new.txt │ │ sec/op │ sec/op vs base │ SetBody/SetBody-12 196.5n ± 14% 365.9n ± 4% +86.26% (p=0.000 n=10) │ old.txt │ new.txt │ │ B/op │ B/op vs base │ SetBody/SetBody-12 363.0 ± 0% 363.0 ± 0% ~ (p=1.000 n=10) ¹ ¹ all samples are equal │ old.txt │ new.txt │ │ allocs/op │ allocs/op vs base │ SetBody/SetBody-12 4.000 ± 0% 4.000 ± 0% ~ (p=1.000 n=10) ¹ ¹ all samples are equal ``` --------- Co-authored-by: Robert Pająk <[email protected]>
1 parent 3cd63fa commit a8e1500

File tree

5 files changed

+176
-16
lines changed

5 files changed

+176
-16
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -71,6 +71,7 @@ The next release will require at least [Go 1.24].
7171
### Fixed
7272

7373
- Fix `go.opentelemetry.io/otel/exporters/prometheus` to deduplicate suffixes if already present in metric name when UTF8 is enabled. (#7088)
74+
- `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)
7475
- Fix the `go.opentelemetry.io/otel/exporters/stdout/stdouttrace` self-observability component type and name. (#7195)
7576
- Fix partial export count metric in `go.opentelemetry.io/otel/exporters/stdout/stdouttrace`. (#7199)
7677

‎sdk/log/logger.go‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -108,7 +108,6 @@ func (l *logger) newRecord(ctx context.Context, r log.Record) Record {
108108
observedTimestamp: r.ObservedTimestamp(),
109109
severity: r.Severity(),
110110
severityText: r.SeverityText(),
111-
body: r.Body(),
112111

113112
traceID: sc.TraceID(),
114113
spanID: sc.SpanID(),
@@ -124,6 +123,9 @@ func (l *logger) newRecord(ctx context.Context, r log.Record) Record {
124123
l.logCreatedMetric.Add(ctx, 1)
125124
}
126125

126+
// This ensures we deduplicate key-value collections in the log body
127+
newRecord.SetBody(r.Body())
128+
127129
// This field SHOULD be set once the event is observed by OpenTelemetry.
128130
if newRecord.observedTimestamp.IsZero() {
129131
newRecord.observedTimestamp = now()

‎sdk/log/logger_test.go‎

Lines changed: 53 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -57,10 +57,20 @@ func TestLoggerEmit(t *testing.T) {
5757
rWithNoObservedTimestamp := r
5858
rWithNoObservedTimestamp.SetObservedTimestamp(time.Time{})
5959

60-
rWithoutDeduplicateAttributes := r
61-
rWithoutDeduplicateAttributes.AddAttributes(
60+
rWithAllowKeyDuplication := r
61+
rWithAllowKeyDuplication.AddAttributes(
6262
log.String("k1", "str1"),
6363
)
64+
rWithAllowKeyDuplication.SetBody(log.MapValue(
65+
log.Int64("1", 2),
66+
log.Int64("1", 3),
67+
))
68+
69+
rWithDuplicatesInBody := r
70+
rWithDuplicatesInBody.SetBody(log.MapValue(
71+
log.Int64("1", 2),
72+
log.Int64("1", 3),
73+
))
6474

6575
contextWithSpanContext := trace.ContextWithSpanContext(
6676
context.Background(),
@@ -222,7 +232,7 @@ func TestLoggerEmit(t *testing.T) {
222232
},
223233
},
224234
{
225-
name: "WithoutAttributeDeduplication",
235+
name: "WithAllowKeyDuplication",
226236
logger: newLogger(NewLoggerProvider(
227237
WithProcessor(p0),
228238
WithProcessor(p1),
@@ -232,15 +242,15 @@ func TestLoggerEmit(t *testing.T) {
232242
WithAllowKeyDuplication(),
233243
), instrumentation.Scope{Name: "scope"}),
234244
ctx: context.Background(),
235-
record: rWithoutDeduplicateAttributes,
245+
record: rWithAllowKeyDuplication,
236246
expectedRecords: []Record{
237247
{
238-
eventName: r.EventName(),
239-
timestamp: r.Timestamp(),
240-
body: r.Body(),
241-
severity: r.Severity(),
242-
severityText: r.SeverityText(),
243-
observedTimestamp: r.ObservedTimestamp(),
248+
eventName: rWithAllowKeyDuplication.EventName(),
249+
timestamp: rWithAllowKeyDuplication.Timestamp(),
250+
body: rWithAllowKeyDuplication.Body(),
251+
severity: rWithAllowKeyDuplication.Severity(),
252+
severityText: rWithAllowKeyDuplication.SeverityText(),
253+
observedTimestamp: rWithAllowKeyDuplication.ObservedTimestamp(),
244254
resource: resource.NewSchemaless(attribute.String("key", "value")),
245255
attributeValueLengthLimit: 5,
246256
attributeCountLimit: 5,
@@ -255,6 +265,39 @@ func TestLoggerEmit(t *testing.T) {
255265
},
256266
},
257267
},
268+
{
269+
name: "WithDuplicatesInBody",
270+
logger: newLogger(NewLoggerProvider(
271+
WithProcessor(p0),
272+
WithProcessor(p1),
273+
WithAttributeValueLengthLimit(5),
274+
WithAttributeCountLimit(5),
275+
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
276+
), instrumentation.Scope{Name: "scope"}),
277+
ctx: context.Background(),
278+
record: rWithDuplicatesInBody,
279+
expectedRecords: []Record{
280+
{
281+
eventName: rWithDuplicatesInBody.EventName(),
282+
timestamp: rWithDuplicatesInBody.Timestamp(),
283+
body: log.MapValue(
284+
log.Int64("1", 3),
285+
),
286+
severity: rWithDuplicatesInBody.Severity(),
287+
severityText: rWithDuplicatesInBody.SeverityText(),
288+
observedTimestamp: rWithDuplicatesInBody.ObservedTimestamp(),
289+
resource: resource.NewSchemaless(attribute.String("key", "value")),
290+
attributeValueLengthLimit: 5,
291+
attributeCountLimit: 5,
292+
scope: &instrumentation.Scope{Name: "scope"},
293+
front: [attributesInlineCount]log.KeyValue{
294+
log.String("k1", "str"),
295+
log.Float64("k2", 1.0),
296+
},
297+
nFront: 2,
298+
},
299+
},
300+
},
258301
}
259302

260303
for _, tc := range testCases {

‎sdk/log/record.go‎

Lines changed: 23 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -170,7 +170,11 @@ func (r *Record) Body() log.Value {
170170

171171
// SetBody sets the body of the log record.
172172
func (r *Record) SetBody(v log.Value) {
173-
r.body = v
173+
if !r.allowDupKeys {
174+
r.body = r.dedupeBodyCollections(v)
175+
} else {
176+
r.body = v
177+
}
174178
}
175179

176180
// WalkAttributes walks all attributes the log record holds by calling f for
@@ -452,6 +456,24 @@ func (r *Record) applyValueLimits(val log.Value) log.Value {
452456
return val
453457
}
454458

459+
func (r *Record) dedupeBodyCollections(val log.Value) log.Value {
460+
switch val.Kind() {
461+
case log.KindSlice:
462+
sl := val.AsSlice()
463+
for i := range sl {
464+
sl[i] = r.dedupeBodyCollections(sl[i])
465+
}
466+
val = log.SliceValue(sl...)
467+
case log.KindMap:
468+
kvs, _ := dedup(val.AsMap())
469+
for i := range kvs {
470+
kvs[i].Value = r.dedupeBodyCollections(kvs[i].Value)
471+
}
472+
val = log.MapValue(kvs...)
473+
}
474+
return val
475+
}
476+
455477
// truncate returns a truncated version of s such that it contains less than
456478
// the limit number of characters. Truncation is applied by returning the limit
457479
// number of valid characters contained in s.

‎sdk/log/record_test.go‎

Lines changed: 96 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -56,10 +56,82 @@ func TestRecordSeverityText(t *testing.T) {
5656
}
5757

5858
func TestRecordBody(t *testing.T) {
59-
v := log.BoolValue(true)
60-
r := new(Record)
61-
r.SetBody(v)
62-
assert.True(t, v.Equal(r.Body()))
59+
testcases := []struct {
60+
name string
61+
allowDuplicates bool
62+
body log.Value
63+
want log.Value
64+
}{
65+
{
66+
name: "Bool",
67+
body: log.BoolValue(true),
68+
want: log.BoolValue(true),
69+
},
70+
{
71+
name: "slice",
72+
body: log.SliceValue(log.BoolValue(true), log.BoolValue(false)),
73+
want: log.SliceValue(log.BoolValue(true), log.BoolValue(false)),
74+
},
75+
{
76+
name: "map",
77+
body: log.MapValue(
78+
log.Bool("0", true),
79+
log.Int64("1", 2), // This should be removed
80+
log.Float64("2", 3.0),
81+
log.String("3", "forth"),
82+
log.Slice("4", log.Int64Value(1)),
83+
log.Map("5", log.Int("key", 2)),
84+
log.Bytes("6", []byte("six")),
85+
log.Int64("1", 3),
86+
),
87+
want: log.MapValue(
88+
log.Bool("0", true),
89+
log.Float64("2", 3.0),
90+
log.String("3", "forth"),
91+
log.Slice("4", log.Int64Value(1)),
92+
log.Map("5", log.Int("key", 2)),
93+
log.Bytes("6", []byte("six")),
94+
log.Int64("1", 3),
95+
),
96+
},
97+
{
98+
name: "nestedMap",
99+
body: log.MapValue(
100+
log.Map("key",
101+
log.Int64("key", 1),
102+
log.Int64("key", 2),
103+
),
104+
),
105+
want: log.MapValue(
106+
log.Map("key",
107+
log.Int64("key", 2),
108+
),
109+
),
110+
},
111+
{
112+
name: "map - allow duplicates",
113+
allowDuplicates: true,
114+
body: log.MapValue(
115+
log.Int64("1", 2),
116+
log.Int64("1", 3),
117+
),
118+
want: log.MapValue(
119+
log.Int64("1", 2),
120+
log.Int64("1", 3),
121+
),
122+
},
123+
}
124+
for _, tc := range testcases {
125+
t.Run(tc.name, func(t *testing.T) {
126+
r := new(Record)
127+
r.allowDupKeys = tc.allowDuplicates
128+
r.SetBody(tc.body)
129+
got := r.Body()
130+
if !got.Equal(tc.want) {
131+
t.Errorf("r.Body() = %v, want %v", got, tc.want)
132+
}
133+
})
134+
}
63135
}
64136

65137
func TestRecordAttributes(t *testing.T) {
@@ -951,3 +1023,23 @@ func BenchmarkSetAddAttributes(b *testing.B) {
9511023
}
9521024
})
9531025
}
1026+
1027+
func BenchmarkSetBody(b *testing.B) {
1028+
b.Run("SetBody", func(b *testing.B) {
1029+
records := make([]Record, b.N)
1030+
1031+
b.ResetTimer()
1032+
b.ReportAllocs()
1033+
for i := 0; i < b.N; i++ {
1034+
records[i].SetBody(log.MapValue(
1035+
log.Bool("0", true),
1036+
log.Float64("2", 3.0),
1037+
log.String("3", "forth"),
1038+
log.Slice("4", log.Int64Value(1)),
1039+
log.Map("5", log.Int("key", 2)),
1040+
log.Bytes("6", []byte("six")),
1041+
log.Int64("1", 3),
1042+
))
1043+
}
1044+
})
1045+
}

0 commit comments

Comments
 (0)