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

otelzap: Use pool for encoder #5719

Closed
wants to merge 15 commits into from
Closed
Show file tree
Hide file tree
Changes from 11 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions bridges/otelzap/core.go
Original file line number Diff line number Diff line change
Expand Up @@ -172,9 +172,9 @@ func (o *Core) Write(ent zapcore.Entry, fields []zapcore.Field) error {
}

func convertField(fields []zapcore.Field) (context.Context, []log.KeyValue) {
// TODO: Use objectEncoder from a pool instead of newObjectEncoder.
var ctx context.Context
enc := newObjectEncoder(len(fields))
enc, free := getObjectEncoder()
defer free()
for _, field := range fields {
if ctxFld, ok := field.Interface.(context.Context); ok {
ctx = ctxFld
Expand Down
44 changes: 38 additions & 6 deletions bridges/otelzap/encoder.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,13 +6,47 @@ package otelzap // import "go.opentelemetry.io/contrib/bridges/otelzap"
import (
"fmt"
"reflect"
"sync"
"time"

"go.uber.org/zap/zapcore"

"go.opentelemetry.io/otel/log"
)

var arrayEncoderPool = sync.Pool{
New: func() interface{} {
// Similar to console_encoder which uses capacity of 2
return &arrayEncoder{elems: make([]log.Value, 0, 2)}
},
}

func getArrayEncoder() (arr *arrayEncoder, free func()) {
arr = arrayEncoderPool.Get().(*arrayEncoder)
return arr, func() {
arr.elems = arr.elems[:0]
Copy link
Member

Choose a reason for hiding this comment

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

Can you add this comment?

// 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

arrayEncoderPool.Put(arr)
}
}

var objectEncoderPool = sync.Pool{
New: func() interface{} {
// Similar to console_encoder which uses capacity of 2
return newObjectEncoder(2)
},
}

func getObjectEncoder() (obj *objectEncoder, free func()) {
obj = objectEncoderPool.Get().(*objectEncoder)
return obj, func() {
obj.root.attrs = obj.root.attrs[:0]
Copy link
Member

Choose a reason for hiding this comment

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

Can you add this comment?

// 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

obj.root.name = ""
obj.root.next = nil
obj.cur = obj.root
objectEncoderPool.Put(obj)
}
}

var (
_ zapcore.ObjectEncoder = (*objectEncoder)(nil)
_ zapcore.ArrayEncoder = (*arrayEncoder)(nil)
Expand Down Expand Up @@ -55,16 +89,16 @@ func (m *objectEncoder) calculate(o *namespace) {
}

func (m *objectEncoder) AddArray(key string, v zapcore.ArrayMarshaler) error {
// TODO: Use arrayEncoder from a pool.
arr := &arrayEncoder{}
arr, free := getArrayEncoder()
defer free()
err := v.MarshalLogArray(arr)
m.cur.attrs = append(m.cur.attrs, log.Slice(key, arr.elems...))
return err
}

func (m *objectEncoder) AddObject(k string, v zapcore.ObjectMarshaler) error {
// TODO: Use objectEncoder from a pool.
newobj := newObjectEncoder(2)
newobj, free := getObjectEncoder()
defer free()
err := v.MarshalLogObject(newobj)
newobj.calculate(newobj.root)
m.cur.attrs = append(m.cur.attrs, log.Map(k, newobj.root.attrs...))
Expand Down Expand Up @@ -196,15 +230,13 @@ type arrayEncoder struct {
}

func (a *arrayEncoder) AppendArray(v zapcore.ArrayMarshaler) error {
// TODO: Use arrayEncoder from a pool.
Copy link
Contributor Author

@khushijain21 khushijain21 Jun 26, 2024

Choose a reason for hiding this comment

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

adding sync.pool here does not improve performance

Copy link
Contributor

Choose a reason for hiding this comment

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

What benchmark was used to see this?

Copy link
Contributor Author

@khushijain21 khushijain21 Jul 4, 2024

Choose a reason for hiding this comment

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

not entirely sure why, but using pool in AppendArray and AppendObject seems to be causing shared memory issue. I visualised one of the failures with nested cases. For now, I avoid using pool for AppendArray and AppendObject.

This behaviour is not seen outside of this.

Capture3

Copy link
Member

Choose a reason for hiding this comment

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

At quick glance, I think that the issue is caused by the fact that in array encoder free function does:

arr.elems = arr.elems[:0]

which causes to reuse the same underlying array. The next ArrayAppender is going to access the same elements when doing

err := v.MarshalLogArray(arr)

before the logs are emitted

I suggest not using the pooled encoder for AppendArray and AppendObject in scope of this PR.

I think (hope) that AppendArray and AppendObject are not going to be frequently invoked/used by the bridge users.

Copy link
Member

@pellared pellared Jul 9, 2024

Choose a reason for hiding this comment

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

I think the same problem with using shared memory applies for AddArray and AddObject. Similarly to #5879.

Probably we miss some unit test that would detect it.

arr := &arrayEncoder{}
err := v.MarshalLogArray(arr)
a.elems = append(a.elems, log.SliceValue(arr.elems...))
return err
}

func (a *arrayEncoder) AppendObject(v zapcore.ObjectMarshaler) error {
// TODO: Use objectEncoder from a pool.
m := newObjectEncoder(2)
err := v.MarshalLogObject(m)
m.calculate(m.root)
Expand Down
26 changes: 26 additions & 0 deletions bridges/otelzap/encoder_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ package otelzap

import (
"errors"
"fmt"
"testing"
"time"

Expand Down Expand Up @@ -55,6 +56,7 @@ func TestObjectEncoder(t *testing.T) {
arr.AppendBool(true)
return nil
})), "Expected AddArray to succeed.")

},
expected: []interface{}{true, false, true},
},
Expand All @@ -65,6 +67,13 @@ func TestObjectEncoder(t *testing.T) {
},
expected: []interface{}{wantTurducken, wantTurducken},
},
{
desc: "AddArray-with AppendArray",
f: func(e zapcore.ObjectEncoder) {
assert.NoError(t, e.AddArray("k", number(2)), "Expected AddArray to succeed.")
},
expected: []interface{}{[]interface{}{"1"}, []interface{}{"2"}},
},
{
desc: "AddReflected",
f: func(e zapcore.ObjectEncoder) {
Expand Down Expand Up @@ -361,6 +370,23 @@ func (t turduckens) MarshalLogArray(enc zapcore.ArrayEncoder) error {
return err
}

type number int

func (t number) MarshalLogArray(enc zapcore.ArrayEncoder) error {
var err error
for i := 0; i < int(t); i++ {
err = errors.Join(err, enc.AppendArray(numberString(fmt.Sprint(i+1))))
}
return err
}

type numberString string

func (t numberString) MarshalLogArray(enc zapcore.ArrayEncoder) error {
enc.AppendString(string(t))
return nil
}

type loggable struct{ bool }

func (l loggable) MarshalLogObject(enc zapcore.ObjectEncoder) error {
Expand Down
Loading