Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log a warning when log Record attribute is dropped #5376

Merged
merged 11 commits into from
May 28, 2024
4 changes: 4 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,10 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm

## [Unreleased]

### Fixed

- Log a warning to the OpenTelemetry internal logger when a `Record` in `go.opentelemetry.io/otel/sdk/log` drops an attribute due to a limit being reached. (#5376)

## [1.27.0/0.49.0/0.3.0] 2024-05-21

### Added
Expand Down
37 changes: 27 additions & 10 deletions sdk/log/record.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"time"
"unicode/utf8"

"go.opentelemetry.io/otel/internal/global"
"go.opentelemetry.io/otel/log"
"go.opentelemetry.io/otel/sdk/instrumentation"
"go.opentelemetry.io/otel/sdk/resource"
Expand All @@ -22,6 +23,10 @@ import (
// cover 95% of all use-cases (https://go.dev/blog/slog#performance).
const attributesInlineCount = 5

var logAttrDropped = sync.OnceFunc(func() {
MrAlias marked this conversation as resolved.
Show resolved Hide resolved
global.Warn("limit reached: dropping log Record attributes")
})

// indexPool is a pool of index maps used for de-duplication.
var indexPool = sync.Pool{
New: func() any { return make(map[string]int) },
Expand Down Expand Up @@ -83,6 +88,16 @@ type Record struct {
attributeCountLimit int
}

func (r *Record) addDropped(n int) {
logAttrDropped()
r.dropped += n
}

func (r *Record) setDropped(n int) {
logAttrDropped()
r.dropped = n
}

// Timestamp returns the time when the log record occurred.
func (r *Record) Timestamp() time.Time {
return r.timestamp
Expand Down Expand Up @@ -155,11 +170,12 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) {
n := r.AttributesLen()
if n == 0 {
// Avoid the more complex duplicate map lookups below.
attrs, r.dropped = dedup(attrs)

var drop int
attrs, drop = dedup(attrs)
r.setDropped(drop)

attrs, drop = head(attrs, r.attributeCountLimit)
r.dropped += drop
r.addDropped(drop)

r.addAttrs(attrs)
return
Expand All @@ -184,15 +200,15 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) {
// Last-value-wins for any duplicates in attrs.
idx, found := uIndex[a.Key]
if found {
r.dropped++
r.addDropped(1)
unique[idx] = a
continue
}

idx, found = rIndex[a.Key]
if found {
// New attrs overwrite any existing with the same key.
r.dropped++
r.addDropped(1)
if idx < 0 {
r.front[-(idx + 1)] = a
} else {
Expand All @@ -212,7 +228,7 @@ func (r *Record) AddAttributes(attrs ...log.KeyValue) {
// 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
r.addDropped(len(attrs) - last)
attrs = attrs[:last]
}

Expand Down Expand Up @@ -261,11 +277,12 @@ func (r *Record) addAttrs(attrs []log.KeyValue) {
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
attrs, drop = dedup(attrs)
r.setDropped(drop)

attrs, drop = head(attrs, r.attributeCountLimit)
r.dropped += drop
r.addDropped(drop)

r.nFront = 0
var i int
Expand Down Expand Up @@ -396,7 +413,7 @@ func (r Record) applyValueLimits(val log.Value) log.Value {
// Deduplicate then truncate. Do not do at the same time to avoid
// wasted truncation operations.
kvs, dropped := dedup(val.AsMap())
r.dropped += dropped
r.addDropped(dropped)
for i := range kvs {
kvs[i] = r.applyAttrLimits(kvs[i])
}
Expand Down
9 changes: 9 additions & 0 deletions sdk/log/record_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -196,14 +196,23 @@ func TestRecordClone(t *testing.T) {
}

func TestRecordDroppedAttributes(t *testing.T) {
orig := logAttrDropped
t.Cleanup(func() { logAttrDropped = orig })

for i := 1; i < attributesInlineCount*5; i++ {
var called bool
logAttrDropped = func() { called = true }

r := new(Record)
r.attributeCountLimit = 1

attrs := make([]log.KeyValue, i)
attrs[0] = log.Bool("only key different then the rest", true)
assert.False(t, called, "non-dropped attributed logged")

r.AddAttributes(attrs...)
assert.Equalf(t, i-1, r.DroppedAttributes(), "%d: AddAttributes", i)
assert.True(t, called, "dropped attributes not logged")

r.AddAttributes(attrs...)
assert.Equalf(t, 2*i-1, r.DroppedAttributes(), "%d: second AddAttributes", i)
Expand Down