otelzap: Use pool for encoder #5719

khushijain21 · 2024-06-04T05:37:47Z

Part of #5191

Pre-work #5279

Results:

goos: linux
goarch: amd64
pkg: go.opentelemetry.io/contrib/bridges/otelzap
cpu: 12th Gen Intel(R) Core(TM) i5-1245U
                           │ old_bench.txt │            new_bench.txt             │
                           │    sec/op     │    sec/op     vs base                │
CoreWrite/10_fields-12       1170.5n ± 28%   511.8n ± 44%  -56.28% (p=0.000 n=10)
CoreWrite/20_fields-12        2.665µ ± 24%   1.441µ ± 20%  -45.93% (p=0.000 n=10)
CoreWrite/Namespace-12        2.057µ ± 29%   1.211µ ±  5%  -41.13% (p=0.000 n=10)
CoreWrite/With10_fields-12    249.3n ± 22%   186.4n ± 21%  -25.23% (p=0.015 n=10)
CoreWrite/With20_fields-12    716.5n ± 30%   513.4n ± 40%        ~ (p=0.072 n=10)
CoreWrite/WithNamespace-12    24.39n ± 22%   14.16n ± 20%  -41.93% (p=0.000 n=10)
geomean                       550.9n         326.4n        -40.74%

                           │ old_bench.txt  │             new_bench.txt              │
                           │      B/op      │     B/op      vs base                  │
CoreWrite/10_fields-12         978.0 ± 0%       307.0 ± 0%  -68.61% (p=0.000 n=10)
CoreWrite/20_fields-12        2180.0 ± 0%       818.0 ± 0%  -62.48% (p=0.000 n=10)
CoreWrite/Namespace-12       1.719Ki ± 0%     1.002Ki ± 0%  -41.70% (p=0.000 n=10)
CoreWrite/With10_fields-12     208.0 ± 0%       208.0 ± 0%        ~ (p=1.000 n=10) ¹
CoreWrite/With20_fields-12     640.0 ± 0%       640.0 ± 0%        ~ (p=1.000 n=10) ¹
CoreWrite/WithNamespace-12     0.000 ± 0%       0.000 ± 0%        ~ (p=1.000 n=10) ¹
geomean                                   ²                 -36.01%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

                           │ old_bench.txt │            new_bench.txt             │
                           │   allocs/op   │ allocs/op   vs base                  │
CoreWrite/10_fields-12        13.00 ± 0%     10.00 ± 0%  -23.08% (p=0.000 n=10)
CoreWrite/20_fields-12        22.00 ± 0%     17.00 ± 0%  -22.73% (p=0.000 n=10)
CoreWrite/Namespace-12        16.00 ± 0%     13.00 ± 0%  -18.75% (p=0.000 n=10)
CoreWrite/With10_fields-12    1.000 ± 0%     1.000 ± 0%        ~ (p=1.000 n=10) ¹
CoreWrite/With20_fields-12    1.000 ± 0%     1.000 ± 0%        ~ (p=1.000 n=10) ¹
CoreWrite/WithNamespace-12    0.000 ± 0%     0.000 ± 0%        ~ (p=1.000 n=10) ¹
geomean                                  ²               -11.42%                ²
¹ all samples are equal
² summaries must be >0 to compute geomean

codecov · 2024-06-04T06:13:08Z

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 64.7%. Comparing base (c80e464) to head (c6ab05d).
Report is 7 commits behind head on main.

Additional details and impacted files

@@           Coverage Diff           @@
##            main   #5719     +/-   ##
=======================================
+ Coverage   64.6%   64.7%   +0.1%     
=======================================
  Files        201     201             
  Lines      12587   12626     +39     
=======================================
+ Hits        8134    8173     +39     
  Misses      4216    4216             
  Partials     237     237

Files	Coverage Δ
bridges/otelzap/core.go	`90.0% <100.0%> (+<0.1%)`	⬆️
bridges/otelzap/encoder.go	`87.3% <100.0%> (+1.4%)`	⬆️

... and 3 files with indirect coverage changes

pellared · 2024-06-04T07:22:31Z

Please make sure to add benchmarks to the PRs which are meant to improve performance.
You can also consider creating separate PRs that would contain just benchmarks.

…y-go-contrib into zappool

khushijain21 · 2024-06-26T13:40:44Z

bridges/otelzap/encoder.go

@@ -196,15 +230,13 @@ type arrayEncoder struct {
 }

 func (a *arrayEncoder) AppendArray(v zapcore.ArrayMarshaler) error {
-	// TODO: Use arrayEncoder from a pool.


~~adding sync.pool here does not improve performance~~

What benchmark was used to see this?

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.

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.

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.

pellared · 2024-06-26T14:24:22Z

Please use https://pkg.go.dev/golang.org/x/perf/cmd/benchstat to show the performance improvement (between main and this branch) in the PR description.

…ry-go-contrib into zappool

…y-go-contrib into zappool

khushijain21 · 2024-07-09T09:13:05Z

@pellared

pellared · 2024-07-09T12:18:39Z

bridges/otelzap/encoder.go

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


Can you add this comment?

opentelemetry-go-contrib/bridges/otelslog/handler.go

Lines 352 to 354 in c80e464

// 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 · 2024-07-09T12:18:47Z

bridges/otelzap/encoder.go

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


Can you add this comment?

opentelemetry-go-contrib/bridges/otelslog/handler.go

Lines 352 to 354 in c80e464

// 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 · 2024-07-09T12:19:46Z

Can you please fix the build?

See: https://github.com/open-telemetry/opentelemetry-go-contrib/actions/runs/9854291298/job/27206720483?pr=5719

…ry-go-contrib into zappool

otelzap: Use pool for encoder

7e9fa35

khushijain21 requested a review from pellared as a code owner June 4, 2024 05:37

khushijain21 requested a review from a team June 4, 2024 05:37

khushijain21 marked this pull request as draft June 4, 2024 06:08

Merge branch 'main' into zappool

0b69a51

khushijain21 added 3 commits June 26, 2024 10:50

Merge branch 'main' of https://github.com/open-telemetry/opentelemetr…

ea2f69b

…y-go-contrib into zappool

Merge branch 'main' of https://github.com/open-telemetry/opentelemetr…

aa469d2

…y-go-contrib into zappool

add pool

1aa6bf0

khushijain21 marked this pull request as ready for review June 26, 2024 13:35

khushijain21 commented Jun 26, 2024

View reviewed changes

khushijain21 marked this pull request as draft June 27, 2024 07:13

khushijain21 added 4 commits July 1, 2024 10:39

refactoring

8db2a5e

changes 1

d0c73eb

Merge branch 'zappool' of https://github.com/khushijain21/opentelemet…

5584bc6

…ry-go-contrib into zappool

final changes

04edfe5

khushijain21 marked this pull request as ready for review July 4, 2024 16:58

khushijain21 added 2 commits July 5, 2024 15:11

Merge branch 'main' of https://github.com/open-telemetry/opentelemetr…

eacc943

…y-go-contrib into zappool

Merge branch 'main' into zappool

c480950

khushijain21 requested a review from MrAlias July 9, 2024 04:02

Merge branch 'main' into zappool

d064339

pellared added Skip Changelog Allow PR to succeed without requiring an addition to the CHANGELOG bridge: zap Related to the zap bridge labels Jul 9, 2024

pellared reviewed Jul 9, 2024

View reviewed changes

khushijain21 added 2 commits July 9, 2024 19:20

lint error fixed

7eea197

add more tests

3dc1d31

Merge branch 'zappool' of https://github.com/khushijain21/opentelemet…

c6ab05d

…ry-go-contrib into zappool

khushijain21 closed this Jul 11, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

otelzap: Use pool for encoder #5719

otelzap: Use pool for encoder #5719

khushijain21 commented Jun 4, 2024 •

edited

Loading

codecov bot commented Jun 4, 2024 •

edited

Loading

pellared commented Jun 4, 2024

khushijain21 Jun 26, 2024 •

edited

Loading

MrAlias Jun 26, 2024

khushijain21 Jul 4, 2024 •

edited

Loading

pellared Jul 9, 2024

pellared Jul 9, 2024 •

edited

Loading

pellared commented Jun 26, 2024

khushijain21 commented Jul 9, 2024

pellared Jul 9, 2024

pellared Jul 9, 2024

pellared commented Jul 9, 2024

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

otelzap: Use pool for encoder #5719

otelzap: Use pool for encoder #5719

Conversation

khushijain21 commented Jun 4, 2024 • edited Loading

codecov bot commented Jun 4, 2024 • edited Loading

Codecov Report

pellared commented Jun 4, 2024

khushijain21 Jun 26, 2024 • edited Loading

Choose a reason for hiding this comment

MrAlias Jun 26, 2024

Choose a reason for hiding this comment

khushijain21 Jul 4, 2024 • edited Loading

Choose a reason for hiding this comment

pellared Jul 9, 2024

Choose a reason for hiding this comment

pellared Jul 9, 2024 • edited Loading

Choose a reason for hiding this comment

pellared commented Jun 26, 2024

khushijain21 commented Jul 9, 2024

pellared Jul 9, 2024

Choose a reason for hiding this comment

pellared Jul 9, 2024

Choose a reason for hiding this comment

pellared commented Jul 9, 2024

khushijain21 commented Jun 4, 2024 •

edited

Loading

codecov bot commented Jun 4, 2024 •

edited

Loading

khushijain21 Jun 26, 2024 •

edited

Loading

khushijain21 Jul 4, 2024 •

edited

Loading

pellared Jul 9, 2024 •

edited

Loading