You've already forked opentelemetry-go
mirror of
https://github.com/open-telemetry/opentelemetry-go.git
synced 2026-06-03 18:35:08 +02:00
Joe Stephenson
5da6cd28a8
Closes #5133 This couldn't be added as an option on a processor, as that would involve moving all the attribute deduplication. logic outside of the record type. Instead this PR provides the same functionality but it is set when creating the log provider The below benchstat report shows the performance improvement when `allowDupKeys` is set ``` goos: darwin goarch: arm64 pkg: go.opentelemetry.io/otel/sdk/log cpu: Apple M2 Pro │ withoutDedup.txt │ withDedup.txt │ │ sec/op │ sec/op vs base │ SetAddAttributes/SetAttributes-12 141.3n ± 2% 167.4n ± 5% +18.51% (p=0.000 n=10) SetAddAttributes/AddAttributes-12 117.5n ± 2% 124.8n ± 5% +6.17% (p=0.000 n=10) geomean 128.9n 144.5n +12.17% │ withoutDedup.txt │ withDedup.txt │ │ B/op │ B/op vs base │ SetAddAttributes/SetAttributes-12 48.00 ± 0% 48.00 ± 0% ~ (p=1.000 n=10) ¹ SetAddAttributes/AddAttributes-12 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ geomean ² +0.00% ² ¹ all samples are equal ² summaries must be >0 to compute geomean │ withoutDedup.txt │ withDedup.txt │ │ allocs/op │ allocs/op vs base │ SetAddAttributes/SetAttributes-12 1.000 ± 0% 1.000 ± 0% ~ (p=1.000 n=10) ¹ SetAddAttributes/AddAttributes-12 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ geomean ² +0.00% ² ¹ all samples are equal ² summaries must be >0 to compute geomean ```
351 lines
10 KiB
Go
351 lines
10 KiB
Go
// Copyright The OpenTelemetry Authors
|
|
// SPDX-License-Identifier: Apache-2.0
|
|
|
|
package log // import "go.opentelemetry.io/otel/sdk/log"
|
|
|
|
import (
|
|
"context"
|
|
"errors"
|
|
"testing"
|
|
"time"
|
|
|
|
"github.com/stretchr/testify/assert"
|
|
|
|
"go.opentelemetry.io/otel/attribute"
|
|
"go.opentelemetry.io/otel/log"
|
|
"go.opentelemetry.io/otel/sdk/instrumentation"
|
|
"go.opentelemetry.io/otel/sdk/resource"
|
|
"go.opentelemetry.io/otel/trace"
|
|
)
|
|
|
|
func TestLoggerEmit(t *testing.T) {
|
|
nowDate := time.Date(2010, time.January, 1, 0, 0, 0, 0, time.UTC)
|
|
|
|
nowSwap := now
|
|
t.Cleanup(func() {
|
|
now = nowSwap
|
|
})
|
|
now = func() time.Time {
|
|
return nowDate
|
|
}
|
|
|
|
p0, p1, p2WithError := newProcessor("0"), newProcessor("1"), newProcessor("2")
|
|
p2WithError.Err = errors.New("error")
|
|
|
|
r := log.Record{}
|
|
r.SetEventName("testing.name")
|
|
r.SetTimestamp(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),
|
|
)
|
|
r.SetObservedTimestamp(time.Date(2001, time.January, 1, 0, 0, 0, 0, time.UTC))
|
|
|
|
rWithNoObservedTimestamp := r
|
|
rWithNoObservedTimestamp.SetObservedTimestamp(time.Time{})
|
|
|
|
rWithoutDeduplicateAttributes := r
|
|
rWithoutDeduplicateAttributes.AddAttributes(
|
|
log.String("k1", "str1"),
|
|
)
|
|
|
|
contextWithSpanContext := trace.ContextWithSpanContext(
|
|
context.Background(),
|
|
trace.NewSpanContext(trace.SpanContextConfig{
|
|
TraceID: trace.TraceID{0o1},
|
|
SpanID: trace.SpanID{0o2},
|
|
TraceFlags: 0x1,
|
|
}),
|
|
)
|
|
|
|
testCases := []struct {
|
|
name string
|
|
logger *logger
|
|
ctx context.Context
|
|
record log.Record
|
|
expectedRecords []Record
|
|
}{
|
|
{
|
|
name: "NoProcessors",
|
|
logger: newLogger(NewLoggerProvider(), instrumentation.Scope{}),
|
|
ctx: context.Background(),
|
|
record: r,
|
|
},
|
|
{
|
|
name: "WithProcessors",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
WithAttributeValueLengthLimit(3),
|
|
WithAttributeCountLimit(2),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
record: r,
|
|
expectedRecords: []Record{
|
|
{
|
|
eventName: r.EventName(),
|
|
timestamp: r.Timestamp(),
|
|
body: r.Body(),
|
|
severity: r.Severity(),
|
|
severityText: r.SeverityText(),
|
|
observedTimestamp: r.ObservedTimestamp(),
|
|
resource: resource.NewSchemaless(attribute.String("key", "value")),
|
|
attributeValueLengthLimit: 3,
|
|
attributeCountLimit: 2,
|
|
scope: &instrumentation.Scope{Name: "scope"},
|
|
front: [attributesInlineCount]log.KeyValue{
|
|
log.String("k1", "str"),
|
|
log.Float64("k2", 1.0),
|
|
},
|
|
nFront: 2,
|
|
},
|
|
},
|
|
},
|
|
{
|
|
name: "WithProcessorsWithError",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p2WithError),
|
|
WithAttributeValueLengthLimit(3),
|
|
WithAttributeCountLimit(2),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
},
|
|
{
|
|
name: "WithTraceSpanInContext",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
WithAttributeValueLengthLimit(3),
|
|
WithAttributeCountLimit(2),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: contextWithSpanContext,
|
|
record: r,
|
|
expectedRecords: []Record{
|
|
{
|
|
eventName: r.EventName(),
|
|
timestamp: r.Timestamp(),
|
|
body: r.Body(),
|
|
severity: r.Severity(),
|
|
severityText: r.SeverityText(),
|
|
observedTimestamp: r.ObservedTimestamp(),
|
|
resource: resource.NewSchemaless(attribute.String("key", "value")),
|
|
attributeValueLengthLimit: 3,
|
|
attributeCountLimit: 2,
|
|
scope: &instrumentation.Scope{Name: "scope"},
|
|
front: [attributesInlineCount]log.KeyValue{
|
|
log.String("k1", "str"),
|
|
log.Float64("k2", 1.0),
|
|
},
|
|
nFront: 2,
|
|
traceID: trace.TraceID{0o1},
|
|
spanID: trace.SpanID{0o2},
|
|
traceFlags: 0x1,
|
|
},
|
|
},
|
|
},
|
|
{
|
|
name: "WithNilContext",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
WithAttributeValueLengthLimit(3),
|
|
WithAttributeCountLimit(2),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
record: r,
|
|
expectedRecords: []Record{
|
|
{
|
|
eventName: r.EventName(),
|
|
timestamp: r.Timestamp(),
|
|
body: r.Body(),
|
|
severity: r.Severity(),
|
|
severityText: r.SeverityText(),
|
|
observedTimestamp: r.ObservedTimestamp(),
|
|
resource: resource.NewSchemaless(attribute.String("key", "value")),
|
|
attributeValueLengthLimit: 3,
|
|
attributeCountLimit: 2,
|
|
scope: &instrumentation.Scope{Name: "scope"},
|
|
front: [attributesInlineCount]log.KeyValue{
|
|
log.String("k1", "str"),
|
|
log.Float64("k2", 1.0),
|
|
},
|
|
nFront: 2,
|
|
},
|
|
},
|
|
},
|
|
{
|
|
name: "NoObservedTimestamp",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
WithAttributeValueLengthLimit(3),
|
|
WithAttributeCountLimit(2),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
record: rWithNoObservedTimestamp,
|
|
expectedRecords: []Record{
|
|
{
|
|
eventName: rWithNoObservedTimestamp.EventName(),
|
|
timestamp: rWithNoObservedTimestamp.Timestamp(),
|
|
body: rWithNoObservedTimestamp.Body(),
|
|
severity: rWithNoObservedTimestamp.Severity(),
|
|
severityText: rWithNoObservedTimestamp.SeverityText(),
|
|
observedTimestamp: nowDate,
|
|
resource: resource.NewSchemaless(attribute.String("key", "value")),
|
|
attributeValueLengthLimit: 3,
|
|
attributeCountLimit: 2,
|
|
scope: &instrumentation.Scope{Name: "scope"},
|
|
front: [attributesInlineCount]log.KeyValue{
|
|
log.String("k1", "str"),
|
|
log.Float64("k2", 1.0),
|
|
},
|
|
nFront: 2,
|
|
},
|
|
},
|
|
},
|
|
{
|
|
name: "WithoutAttributeDeduplication",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
WithAttributeValueLengthLimit(5),
|
|
WithAttributeCountLimit(5),
|
|
WithResource(resource.NewSchemaless(attribute.String("key", "value"))),
|
|
WithAllowKeyDuplication(),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
record: rWithoutDeduplicateAttributes,
|
|
expectedRecords: []Record{
|
|
{
|
|
eventName: r.EventName(),
|
|
timestamp: r.Timestamp(),
|
|
body: r.Body(),
|
|
severity: r.Severity(),
|
|
severityText: r.SeverityText(),
|
|
observedTimestamp: r.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),
|
|
log.String("k1", "str1"),
|
|
},
|
|
nFront: 3,
|
|
allowDupKeys: true,
|
|
},
|
|
},
|
|
},
|
|
}
|
|
|
|
for _, tc := range testCases {
|
|
t.Run(tc.name, func(t *testing.T) {
|
|
// Clean up the records before the test.
|
|
p0.records = nil
|
|
p1.records = nil
|
|
|
|
tc.logger.Emit(tc.ctx, tc.record)
|
|
|
|
assert.Equal(t, tc.expectedRecords, p0.records)
|
|
assert.Equal(t, tc.expectedRecords, p1.records)
|
|
})
|
|
}
|
|
}
|
|
|
|
func TestLoggerEnabled(t *testing.T) {
|
|
p0 := newFltrProcessor("0", true)
|
|
p1 := newFltrProcessor("1", true)
|
|
p2WithDisabled := newFltrProcessor("2", false)
|
|
|
|
testCases := []struct {
|
|
name string
|
|
logger *logger
|
|
ctx context.Context
|
|
param log.EnabledParameters
|
|
expected bool
|
|
expectedP0Params []EnabledParameters
|
|
expectedP1Params []EnabledParameters
|
|
expectedP2Params []EnabledParameters
|
|
}{
|
|
{
|
|
name: "NoProcessors",
|
|
logger: newLogger(NewLoggerProvider(), instrumentation.Scope{}),
|
|
ctx: context.Background(),
|
|
expected: false,
|
|
},
|
|
{
|
|
name: "WithProcessors",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
), instrumentation.Scope{Name: "scope"}),
|
|
ctx: context.Background(),
|
|
param: log.EnabledParameters{
|
|
Severity: log.SeverityInfo,
|
|
EventName: "test_event",
|
|
},
|
|
expected: true,
|
|
expectedP0Params: []EnabledParameters{{
|
|
InstrumentationScope: instrumentation.Scope{Name: "scope"},
|
|
Severity: log.SeverityInfo,
|
|
EventName: "test_event",
|
|
}},
|
|
expectedP1Params: nil,
|
|
},
|
|
{
|
|
name: "WithDisabledProcessors",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p2WithDisabled),
|
|
), instrumentation.Scope{}),
|
|
ctx: context.Background(),
|
|
expected: false,
|
|
expectedP2Params: []EnabledParameters{{}},
|
|
},
|
|
{
|
|
name: "ContainsDisabledProcessor",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p2WithDisabled),
|
|
WithProcessor(p0),
|
|
), instrumentation.Scope{}),
|
|
ctx: context.Background(),
|
|
expected: true,
|
|
expectedP2Params: []EnabledParameters{{}},
|
|
expectedP0Params: []EnabledParameters{{}},
|
|
},
|
|
{
|
|
name: "WithNilContext",
|
|
logger: newLogger(NewLoggerProvider(
|
|
WithProcessor(p0),
|
|
WithProcessor(p1),
|
|
), instrumentation.Scope{}),
|
|
ctx: nil,
|
|
expected: true,
|
|
expectedP0Params: []EnabledParameters{{}},
|
|
expectedP1Params: nil,
|
|
},
|
|
}
|
|
|
|
for _, tc := range testCases {
|
|
t.Run(tc.name, func(t *testing.T) {
|
|
// Clean up the records before the test.
|
|
p0.params = nil
|
|
p1.params = nil
|
|
p2WithDisabled.params = nil
|
|
|
|
assert.Equal(t, tc.expected, tc.logger.Enabled(tc.ctx, tc.param))
|
|
assert.Equal(t, tc.expectedP0Params, p0.params)
|
|
assert.Equal(t, tc.expectedP1Params, p1.params)
|
|
assert.Equal(t, tc.expectedP2Params, p2WithDisabled.params)
|
|
})
|
|
}
|
|
}
|