You've already forked opentelemetry-go
mirror of
https://github.com/open-telemetry/opentelemetry-go.git
synced 2026-06-19 21:45:50 +02:00
log: add error field to Record and make SDK to emit exception attributes (#7924)
Fixes #7923 ```sh $ go test -run=^$ -bench=BenchmarkLoggerEmitExceptionAttributes -benchmem -count=5 -benchtime=500ms -cpu=1 goos: darwin goarch: arm64 pkg: go.opentelemetry.io/otel/sdk/log cpu: Apple M4 Pro BenchmarkLoggerSetErrAndEmit 628162 1023 ns/op 5371 B/op 1 allocs/op BenchmarkLoggerSetErrAndEmit 663955 863.3 ns/op 5105 B/op 1 allocs/op BenchmarkLoggerSetErrAndEmit 653888 1067 ns/op 5177 B/op 1 allocs/op BenchmarkLoggerSetErrAndEmit 716438 824.8 ns/op 4764 B/op 1 allocs/op BenchmarkLoggerSetErrAndEmit 746902 999.2 ns/op 5630 B/op 1 allocs/op BenchmarkLoggerSetExceptionAttributesAndEmit 650696 1042 ns/op 5200 B/op 1 allocs/op BenchmarkLoggerSetExceptionAttributesAndEmit 574962 980.7 ns/op 4743 B/op 1 allocs/op BenchmarkLoggerSetExceptionAttributesAndEmit 536736 989.2 ns/op 5049 B/op 1 allocs/op BenchmarkLoggerSetExceptionAttributesAndEmit 558511 1190 ns/op 4870 B/op 1 allocs/op BenchmarkLoggerSetExceptionAttributesAndEmit 669452 978.8 ns/op 5067 B/op 1 allocs/op PASS ok go.opentelemetry.io/otel/sdk/log 6.994s ``` TODO after merged: - https://github.com/open-telemetry/opentelemetry-go/pull/7924#discussion_r2832906451 --------- Signed-off-by: Israel Blancas <iblancasa@gmail.com> Co-authored-by: Robert Pająk <pellared@hotmail.com> Co-authored-by: Damien Mathieu <42@dmathieu.com>
This commit is contained in:
@@ -13,6 +13,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm
|
||||
- Add `go.opentelemetry.io/otel/semconv/v1.40.0` package.
|
||||
The package contains semantic conventions from the `v1.40.0` version of the OpenTelemetry Semantic Conventions.
|
||||
See the [migration documentation](./semconv/v1.40.0/MIGRATION.md) for information on how to upgrade from `go.opentelemetry.io/otel/semconv/v1.39.0`. (#7985)
|
||||
- Add `Err` and `SetErr` on `Record` in `go.opentelemetry.io/otel/log` to attach an error and set record exception attributes in `go.opentelemetry.io/otel/log/sdk`. (#7924)
|
||||
|
||||
### Changed
|
||||
|
||||
|
||||
@@ -26,6 +26,7 @@ type Record struct {
|
||||
severity Severity
|
||||
severityText string
|
||||
body Value
|
||||
err error
|
||||
|
||||
// The fields below are for optimizing the implementation of Attributes and
|
||||
// AddAttributes. This design is borrowed from the slog Record type:
|
||||
@@ -110,6 +111,16 @@ func (r *Record) SetBody(v Value) {
|
||||
r.body = v
|
||||
}
|
||||
|
||||
// Err returns the associated error if one has been set.
|
||||
func (r *Record) Err() error {
|
||||
return r.err
|
||||
}
|
||||
|
||||
// SetErr sets the associated error. Passing nil clears the error.
|
||||
func (r *Record) SetErr(err error) {
|
||||
r.err = err
|
||||
}
|
||||
|
||||
// WalkAttributes walks all attributes the log record holds by calling f for
|
||||
// each on each [KeyValue] in the [Record]. Iteration stops if f returns false.
|
||||
func (r *Record) WalkAttributes(f func(KeyValue) bool) {
|
||||
|
||||
@@ -221,3 +221,39 @@ func TestRecordClone(t *testing.T) {
|
||||
assert.Contains(t, r1Attrs, attr0)
|
||||
assert.Contains(t, r1Attrs, attr1)
|
||||
}
|
||||
|
||||
func TestRecordErr(t *testing.T) {
|
||||
tests := []struct {
|
||||
name string
|
||||
fn func(*log.Record)
|
||||
want error
|
||||
}{
|
||||
{
|
||||
name: "zero value",
|
||||
},
|
||||
{
|
||||
name: "set error",
|
||||
fn: func(r *log.Record) {
|
||||
r.SetErr(assert.AnError)
|
||||
},
|
||||
want: assert.AnError,
|
||||
},
|
||||
{
|
||||
name: "clear error",
|
||||
fn: func(r *log.Record) {
|
||||
r.SetErr(assert.AnError)
|
||||
r.SetErr(nil)
|
||||
},
|
||||
},
|
||||
}
|
||||
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
var r log.Record
|
||||
if tt.fn != nil {
|
||||
tt.fn(&r)
|
||||
}
|
||||
assert.Equal(t, tt.want, r.Err())
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
@@ -5,17 +5,25 @@ package log // import "go.opentelemetry.io/otel/sdk/log"
|
||||
|
||||
import (
|
||||
"context"
|
||||
"reflect"
|
||||
"time"
|
||||
|
||||
"go.opentelemetry.io/otel"
|
||||
"go.opentelemetry.io/otel/log"
|
||||
"go.opentelemetry.io/otel/log/embedded"
|
||||
"go.opentelemetry.io/otel/sdk/instrumentation"
|
||||
semconv "go.opentelemetry.io/otel/semconv/v1.40.0"
|
||||
"go.opentelemetry.io/otel/trace"
|
||||
)
|
||||
|
||||
var now = time.Now
|
||||
|
||||
const (
|
||||
exceptionTypeKey = string(semconv.ExceptionTypeKey)
|
||||
exceptionMessageKey = string(semconv.ExceptionMessageKey)
|
||||
exceptionStacktraceKey = string(semconv.ExceptionStacktraceKey)
|
||||
)
|
||||
|
||||
// Compile-time check logger implements log.Logger.
|
||||
var _ log.Logger = (*logger)(nil)
|
||||
|
||||
@@ -108,10 +116,70 @@ func (l *logger) newRecord(ctx context.Context, r log.Record) Record {
|
||||
newRecord.observedTimestamp = now()
|
||||
}
|
||||
|
||||
hasExceptionAttr := false
|
||||
r.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
switch kv.Key {
|
||||
case exceptionTypeKey, exceptionMessageKey, exceptionStacktraceKey:
|
||||
hasExceptionAttr = true
|
||||
}
|
||||
newRecord.AddAttributes(kv)
|
||||
return true
|
||||
})
|
||||
|
||||
if err := r.Err(); err != nil && !hasExceptionAttr {
|
||||
addExceptionAttrs(&newRecord, err)
|
||||
}
|
||||
|
||||
return newRecord
|
||||
}
|
||||
|
||||
func addExceptionAttrs(r *Record, err error) {
|
||||
var attrs [2]log.KeyValue
|
||||
n := 0
|
||||
if msg := err.Error(); msg != "" {
|
||||
if r.attributeCountLimit > 0 && r.attributeCountLimit-r.AttributesLen() < n+1 {
|
||||
goto flush
|
||||
}
|
||||
attrs[n] = log.String(exceptionMessageKey, msg)
|
||||
n++
|
||||
}
|
||||
if errType := errorType(err); errType != "" {
|
||||
if r.attributeCountLimit > 0 && r.attributeCountLimit-r.AttributesLen() < n+1 {
|
||||
goto flush
|
||||
}
|
||||
attrs[n] = log.String(exceptionTypeKey, errType)
|
||||
n++
|
||||
}
|
||||
|
||||
flush:
|
||||
if n > 0 {
|
||||
r.addAttrs(attrs[:n])
|
||||
}
|
||||
}
|
||||
|
||||
func errorType(err error) string {
|
||||
if et, ok := err.(interface{ ErrorType() string }); ok {
|
||||
if s := et.ErrorType(); s != "" {
|
||||
return s
|
||||
}
|
||||
}
|
||||
|
||||
t := reflect.TypeOf(err)
|
||||
if t == nil {
|
||||
return ""
|
||||
}
|
||||
|
||||
pkg, name := t.PkgPath(), t.Name()
|
||||
if pkg != "" && name != "" {
|
||||
return pkg + "." + name
|
||||
}
|
||||
|
||||
// The type has no package path or name (predeclared, not-defined,
|
||||
// or alias for a not-defined type).
|
||||
//
|
||||
// The type has no package path or name (predeclared, not-defined,
|
||||
// or alias for a not-defined type).
|
||||
//
|
||||
// This is not guaranteed to be unique, but is a best effort.
|
||||
return t.String()
|
||||
}
|
||||
|
||||
@@ -4,6 +4,7 @@
|
||||
package log // import "go.opentelemetry.io/otel/sdk/log"
|
||||
|
||||
import (
|
||||
"errors"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
@@ -14,6 +15,7 @@ import (
|
||||
"go.opentelemetry.io/otel/sdk/instrumentation"
|
||||
"go.opentelemetry.io/otel/sdk/metric"
|
||||
"go.opentelemetry.io/otel/sdk/metric/metricdata"
|
||||
semconv "go.opentelemetry.io/otel/semconv/v1.39.0"
|
||||
)
|
||||
|
||||
func BenchmarkLoggerEmit(b *testing.B) {
|
||||
@@ -119,6 +121,33 @@ func BenchmarkLoggerEnabled(b *testing.B) {
|
||||
_ = enabled
|
||||
}
|
||||
|
||||
func BenchmarkLoggerSetErrAndEmit(b *testing.B) {
|
||||
logger := newTestLogger(b)
|
||||
err := errors.New("boom")
|
||||
|
||||
b.ReportAllocs()
|
||||
b.ResetTimer()
|
||||
for b.Loop() {
|
||||
r := log.Record{}
|
||||
r.SetErr(err)
|
||||
logger.Emit(b.Context(), r)
|
||||
}
|
||||
}
|
||||
|
||||
func BenchmarkLoggerSetExceptionAttributesAndEmit(b *testing.B) {
|
||||
logger := newTestLogger(b)
|
||||
err := errors.New("boom")
|
||||
|
||||
b.ReportAllocs()
|
||||
b.ResetTimer()
|
||||
for b.Loop() {
|
||||
r := log.Record{}
|
||||
r.AddAttributes(log.String(string(semconv.ExceptionMessageKey), err.Error()))
|
||||
r.AddAttributes(log.String(string(semconv.ExceptionTypeKey), errorType(err)))
|
||||
logger.Emit(b.Context(), r)
|
||||
}
|
||||
}
|
||||
|
||||
func newTestLogger(t testing.TB) log.Logger {
|
||||
provider := NewLoggerProvider(
|
||||
WithProcessor(newFltrProcessor("0", false)),
|
||||
|
||||
@@ -314,6 +314,163 @@ func TestLoggerEmit(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestNewRecordAddsExceptionAttrs(t *testing.T) {
|
||||
l := newLogger(NewLoggerProvider(), instrumentation.Scope{})
|
||||
|
||||
t.Run("AddsMissing", func(t *testing.T) {
|
||||
var in log.Record
|
||||
in.SetBody(log.StringValue("boom"))
|
||||
in.SetSeverity(log.SeverityError)
|
||||
in.SetErr(errors.New("boom"))
|
||||
got := l.newRecord(t.Context(), in)
|
||||
|
||||
var gotAttrs []log.KeyValue
|
||||
got.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
gotAttrs = append(gotAttrs, kv)
|
||||
return true
|
||||
})
|
||||
|
||||
assert.Len(t, gotAttrs, 2)
|
||||
assert.Contains(t, gotAttrs, log.String(string(semconv.ExceptionTypeKey), "*errors.errorString"))
|
||||
assert.Contains(t, gotAttrs, log.String(string(semconv.ExceptionMessageKey), "boom"))
|
||||
})
|
||||
|
||||
t.Run("ShortCircuitsAtAttributeLimit", func(t *testing.T) {
|
||||
var in log.Record
|
||||
in.SetBody(log.StringValue("boom"))
|
||||
in.SetSeverity(log.SeverityError)
|
||||
in.SetErr(errors.New("boom"))
|
||||
in.AddAttributes(log.String("k1", "v1"))
|
||||
|
||||
lLimited := newLogger(NewLoggerProvider(WithAttributeCountLimit(2)), instrumentation.Scope{})
|
||||
got := lLimited.newRecord(t.Context(), in)
|
||||
|
||||
var gotType, gotMessage string
|
||||
got.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
switch kv.Key {
|
||||
case string(semconv.ExceptionTypeKey):
|
||||
gotType = kv.Value.AsString()
|
||||
case string(semconv.ExceptionMessageKey):
|
||||
gotMessage = kv.Value.AsString()
|
||||
}
|
||||
return true
|
||||
})
|
||||
|
||||
assert.Empty(t, gotType)
|
||||
assert.Equal(t, "boom", gotMessage)
|
||||
})
|
||||
|
||||
t.Run("NoSlotsLeft", func(t *testing.T) {
|
||||
var in log.Record
|
||||
in.SetBody(log.StringValue("boom"))
|
||||
in.SetSeverity(log.SeverityError)
|
||||
in.SetErr(errors.New("boom"))
|
||||
in.AddAttributes(log.String("k1", "v1"))
|
||||
lLimited := newLogger(NewLoggerProvider(WithAttributeCountLimit(1)), instrumentation.Scope{})
|
||||
got := lLimited.newRecord(t.Context(), in)
|
||||
|
||||
var gotType, gotMessage string
|
||||
got.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
switch kv.Key {
|
||||
case string(semconv.ExceptionTypeKey):
|
||||
gotType = kv.Value.AsString()
|
||||
case string(semconv.ExceptionMessageKey):
|
||||
gotMessage = kv.Value.AsString()
|
||||
}
|
||||
return true
|
||||
})
|
||||
|
||||
assert.Empty(t, gotType)
|
||||
assert.Empty(t, gotMessage)
|
||||
})
|
||||
}
|
||||
|
||||
func TestErrorType(t *testing.T) {
|
||||
t.Run("UsesErrorTypeMethod", func(t *testing.T) {
|
||||
err := errWithType{msg: "boom", typ: "custom.type"}
|
||||
assert.Equal(t, "custom.type", errorType(err))
|
||||
})
|
||||
|
||||
t.Run("FallsBackWhenErrorTypeEmpty", func(t *testing.T) {
|
||||
err := errWithType{msg: "boom", typ: ""}
|
||||
assert.Equal(t, "go.opentelemetry.io/otel/sdk/log.errWithType", errorType(err))
|
||||
})
|
||||
|
||||
t.Run("NilError", func(t *testing.T) {
|
||||
assert.Empty(t, errorType(nil))
|
||||
})
|
||||
|
||||
t.Run("UnnamedType", func(t *testing.T) {
|
||||
var err error = struct{ baseErr }{}
|
||||
assert.Contains(t, errorType(err), "struct")
|
||||
})
|
||||
}
|
||||
|
||||
type errWithType struct {
|
||||
msg string
|
||||
typ string
|
||||
}
|
||||
|
||||
func (e errWithType) Error() string { return e.msg }
|
||||
|
||||
func (e errWithType) ErrorType() string { return e.typ }
|
||||
|
||||
type baseErr struct{}
|
||||
|
||||
func (baseErr) Error() string { return "boom" }
|
||||
|
||||
func TestNewRecordSkipsExceptionWhenPresent(t *testing.T) {
|
||||
l := newLogger(NewLoggerProvider(), instrumentation.Scope{})
|
||||
|
||||
t.Run("ExistingMessage", func(t *testing.T) {
|
||||
var r log.Record
|
||||
r.SetBody(log.StringValue("boom"))
|
||||
r.SetSeverity(log.SeverityError)
|
||||
r.SetErr(errors.New("boom"))
|
||||
r.AddAttributes(log.String(string(semconv.ExceptionMessageKey), "existing.message"))
|
||||
|
||||
got := l.newRecord(t.Context(), r)
|
||||
|
||||
var gotType, gotMessage string
|
||||
got.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
switch kv.Key {
|
||||
case string(semconv.ExceptionTypeKey):
|
||||
gotType = kv.Value.AsString()
|
||||
case string(semconv.ExceptionMessageKey):
|
||||
gotMessage = kv.Value.AsString()
|
||||
}
|
||||
return true
|
||||
})
|
||||
|
||||
assert.Equal(t, "existing.message", gotMessage)
|
||||
assert.Empty(t, gotType)
|
||||
})
|
||||
|
||||
t.Run("ExistingType", func(t *testing.T) {
|
||||
var r log.Record
|
||||
r.SetBody(log.StringValue("boom"))
|
||||
r.SetSeverity(log.SeverityError)
|
||||
r.SetErr(errors.New("boom"))
|
||||
r.AddAttributes(log.String(string(semconv.ExceptionTypeKey), "existing.type"))
|
||||
|
||||
got := l.newRecord(t.Context(), r)
|
||||
|
||||
var gotType, gotMessage string
|
||||
got.WalkAttributes(func(kv log.KeyValue) bool {
|
||||
switch kv.Key {
|
||||
case string(semconv.ExceptionTypeKey):
|
||||
gotType = kv.Value.AsString()
|
||||
case string(semconv.ExceptionMessageKey):
|
||||
gotMessage = kv.Value.AsString()
|
||||
}
|
||||
return true
|
||||
})
|
||||
|
||||
assert.Equal(t, "existing.type", gotType)
|
||||
assert.Empty(t, gotMessage)
|
||||
})
|
||||
}
|
||||
|
||||
func TestLoggerEnabled(t *testing.T) {
|
||||
p0 := newFltrProcessor("0", true)
|
||||
p1 := newFltrProcessor("1", true)
|
||||
|
||||
Reference in New Issue
Block a user