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

Implement the slog Handler functionality #5314

Merged
merged 11 commits into from
Mar 28, 2024
296 changes: 291 additions & 5 deletions bridges/otelslog/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,10 @@

import (
"context"
"fmt"
"log/slog"
"slices"
"sync"

"go.opentelemetry.io/otel/log"
"go.opentelemetry.io/otel/log/global"
Expand Down Expand Up @@ -102,6 +105,8 @@
// Ensure forward compatibility by explicitly making this not comparable.
noCmp [0]func() //nolint: unused // This is indeed used.

attrs *kvBuffer
group *group
logger log.Logger
}

Expand All @@ -124,10 +129,46 @@

// Handle handles the passed record.
func (h *Handler) Handle(ctx context.Context, record slog.Record) error {
// TODO: implement.
h.logger.Emit(ctx, h.convertRecord(record))
return nil
}

func (h *Handler) convertRecord(r slog.Record) log.Record {
var record log.Record
record.SetTimestamp(r.Time)
XSAM marked this conversation as resolved.
Show resolved Hide resolved
record.SetBody(log.StringValue(r.Message))

const sevOffset = slog.Level(log.SeverityDebug) - slog.LevelDebug
record.SetSeverity(log.Severity(r.Level + sevOffset))

if h.attrs.Len() > 0 {
record.AddAttributes(h.attrs.KeyValues()...)
}

n := r.NumAttrs()
if h.group != nil {
if n > 0 {
buf, free := getKVBuffer()
defer free()
r.Attrs(buf.AddAttr)
record.AddAttributes(h.group.KeyValue(buf.KeyValues()...))
} else {
// A Handler should not output groups if there are no attributes.
g := h.group.NextNonEmpty()
if g != nil {
record.AddAttributes(g.KeyValue())
}
}
} else if n > 0 {
buf, free := getKVBuffer()
defer free()
r.Attrs(buf.AddAttr)
record.AddAttributes(buf.KeyValues()...)
}

return record
}

// Enable returns true if the Handler is enabled to log for the provided
// context and Level. Otherwise, false is returned if it is not enabled.
func (h *Handler) Enabled(ctx context.Context, l slog.Level) bool {
Expand All @@ -140,13 +181,258 @@
// WithAttrs returns a new [slog.Handler] based on h that will log using the
// passed attrs.
func (h *Handler) WithAttrs(attrs []slog.Attr) slog.Handler {
// TODO: implement.
return h
h2 := *h
if h2.group != nil {
h2.group = h2.group.Clone()
h2.group.AddAttrs(attrs)
} else {
if h2.attrs == nil {
h2.attrs = newKVBuffer(len(attrs))
} else {
h2.attrs = h2.attrs.Clone()

Check warning on line 192 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L192

Added line #L192 was not covered by tests
}
h2.attrs.AddAttrs(attrs)
}
return &h2
}

// WithGroup returns a new [slog.Handler] based on h that will log all messages
// and attributes within a group of the provided name.
func (h *Handler) WithGroup(name string) slog.Handler {
// TODO: implement.
return h
h2 := *h
h2.group = &group{name: name, next: h2.group}
return &h2
}

// group represents a group received from slog.
type group struct {
// name is the name of the group.
name string
// attrs are the attributes associated with the group.
attrs *kvBuffer
// next points to the next group that holds this group.
//
// Groups are represented as map value types in OpenTelemetry. This means
// that for an slog group hierarchy like the following ...
//
// WithGroup("G").WithGroup("H").WithGroup("I")
//
// the corresponding OpenTelemetry log value types will have the following
// hierarchy ...
//
// KeyValue{
// Key: "G",
// Value: []KeyValue{{
// Key: "H",
// Value: []KeyValue{{
// Key: "I",
// Value: []KeyValue{},
// }},
// }},
// }
//
// When attributes are recorded (i.e. Info("msg", "key", "value") or
// WithAttrs("key", "value")) they need to be added to the "leaf" group. In
// the above example, that would be group "I":
//
// KeyValue{
// Key: "G",
// Value: []KeyValue{{
// Key: "H",
// Value: []KeyValue{{
// Key: "I",
// Value: []KeyValue{
// String("key", "value"),
// },
// }},
// }},
// }
//
// Therefore, groups are structured as a linked-list with the "leaf" node
// being the head of the list. Following the above example, the group data
// representation would be ...
//
// *group{"I", next: *group{"H", next: *group{"G"}}}
next *group
}

// NextNonEmpty returns the next group within g's linked-list that has
// attributes (including g itself). If no group is found, nil is returned.
func (g *group) NextNonEmpty() *group {
if g == nil || g.attrs.Len() > 0 {
return g
}
return g.next.NextNonEmpty()
}

// KeyValue returns group g containing kvs as a [log.KeyValue]. The value of
// the returned KeyValue will be of type [log.KindMap].
//
// The passed kvs are rendered in the returned value, but are not added to the
// group.
//
// This does not check g. It is the callers responsibility to ensure g is
// non-empty or kvs is non-empty so as to return a valid group representation
// (according to slog).
func (g *group) KeyValue(kvs ...log.KeyValue) log.KeyValue {
// Assumes checking of group g already performed (i.e. non-empty).
out := log.Map(g.name, g.attrs.KeyValues(kvs...)...)
g = g.next
for g != nil {
// A Handler should not output groups if there are no attributes.
if g.attrs.Len() > 0 {
out = log.Map(g.name, g.attrs.KeyValues(out)...)
}
g = g.next
}
return out
}

// Clone returns a copy of g.
func (g *group) Clone() *group {
if g == nil {
return g

Check warning on line 294 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L294

Added line #L294 was not covered by tests
}
g2 := *g
g2.attrs = g2.attrs.Clone()
return &g2
}

// AddAttrs add attrs to g.
func (g *group) AddAttrs(attrs []slog.Attr) {
if g.attrs == nil {
g.attrs = newKVBuffer(len(attrs))
}
g.attrs.AddAttrs(attrs)
}

var kvBufferPool = sync.Pool{
New: func() any {
// Based on slog research (https://go.dev/blog/slog#performance), 95%
// of use-cases will use 5 or less attributes.
return newKVBuffer(5)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I used 5 for the array inside a Record because there was a tradeoff: using too much space would hurt performance. There's no similar tradeoff here, so you could make this a bit larger. Maybe 10?

},
}

func getKVBuffer() (buf *kvBuffer, free func()) {
buf = kvBufferPool.Get().(*kvBuffer)
return buf, func() {
// TODO: limit returned size so the pool doesn't hold on to very large
// buffers. Idea is based on
// https://cs.opensource.google/go/x/exp/+/814bf88c:slog/internal/buffer/buffer.go;l=27-34
pellared marked this conversation as resolved.
Show resolved Hide resolved

// Do not modify any previously held data.
buf.data = buf.data[:0:0]
kvBufferPool.Put(buf)
}
}

type kvBuffer struct {
data []log.KeyValue
}

func newKVBuffer(n int) *kvBuffer {
return &kvBuffer{data: make([]log.KeyValue, 0, n)}
}

// Len returns the number of [log.KeyValue] held by b.
func (b *kvBuffer) Len() int {
if b == nil {
return 0
}
return len(b.data)
}

// Clone returns a copy of b.
func (b *kvBuffer) Clone() *kvBuffer {
if b == nil {
return nil
}
return &kvBuffer{data: slices.Clone(b.data)}

Check warning on line 351 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L351

Added line #L351 was not covered by tests
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You lose any extra capacity when you clone b.data, so the subsequent AddAttrs will always allocate. (I think.)

In general though, it's probably best not to worry too much about these details. You can always tweak the performance later.

}

// KeyValues returns kvs appended to the [log.KeyValue] held by b.
func (b *kvBuffer) KeyValues(kvs ...log.KeyValue) []log.KeyValue {
if b == nil {
return kvs
}
return append(b.data, kvs...)
}

// AddAttrs adds attrs to b.
func (b *kvBuffer) AddAttrs(attrs []slog.Attr) {
b.data = slices.Grow(b.data, len(attrs))
for _, a := range attrs {
_ = b.AddAttr(a)
}
}

// AddAttrs adds attr to b and returns true.
MrAlias marked this conversation as resolved.
Show resolved Hide resolved
//
// This is designed to be passed to the AddAttributes method of an
// [slog.Record].
//
// If attr is a group with an empty key, its values will be flattened.
//
// If attr is empty, it will be dropped.
func (b *kvBuffer) AddAttr(attr slog.Attr) bool {
if attr.Key == "" {
if attr.Value.Kind() == slog.KindGroup {
// A Handler should inline the Attrs of a group with an empty key.
for _, a := range attr.Value.Group() {
b.data = append(b.data, log.KeyValue{
Key: a.Key,
Value: convertValue(a.Value),
})
}
return true
}

if attr.Value.Any() == nil {
// A Handler should ignore an empty Attr.
return true
}
}
b.data = append(b.data, log.KeyValue{
Key: attr.Key,
Value: convertValue(attr.Value),
})
return true
}

func convertValue(v slog.Value) log.Value {
MrAlias marked this conversation as resolved.
Show resolved Hide resolved
switch v.Kind() {
case slog.KindAny:
return log.StringValue(fmt.Sprintf("%+v", v.Any()))
case slog.KindBool:
return log.BoolValue(v.Bool())
case slog.KindDuration:
return log.Int64Value(v.Duration().Nanoseconds())
case slog.KindFloat64:
return log.Float64Value(v.Float64())
case slog.KindInt64:
return log.Int64Value(v.Int64())

Check warning on line 414 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L405-L414

Added lines #L405 - L414 were not covered by tests
case slog.KindString:
return log.StringValue(v.String())
case slog.KindTime:
return log.Int64Value(v.Time().UnixNano())
case slog.KindUint64:
return log.Int64Value(int64(v.Uint64()))

Check warning on line 420 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L417-L420

Added lines #L417 - L420 were not covered by tests
case slog.KindGroup:
buf, free := getKVBuffer()
defer free()
buf.AddAttrs(v.Group())
return log.MapValue(buf.data...)
case slog.KindLogValuer:
return convertValue(v.Resolve())
default:

Check warning on line 428 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L428

Added line #L428 was not covered by tests
// Try to handle this as gracefully as possible.
//
// Don't panic here. The goal here is to have developers find this
// first if a new slog.Kind is added. A test on the new kind will find
// this malformed attribute as well as a panic. However, it is
// preferable to have user's open issue asking why their attributes
// have a "unhandled: " prefix than say that their code is panicking.
return log.StringValue(fmt.Sprintf("unhandled: %+v", v.Any()))

Check warning on line 436 in bridges/otelslog/handler.go

View check run for this annotation

Codecov / codecov/patch

bridges/otelslog/handler.go#L436

Added line #L436 was not covered by tests
MrAlias marked this conversation as resolved.
Show resolved Hide resolved
}
}
Loading