From: Sean Liao Date: Sat, 20 Sep 2025 11:33:03 +0000 (+0100) Subject: log/slog: use a pooled json encoder X-Git-Tag: go1.26rc1~818 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=177cd8d763;p=gostls13.git log/slog: use a pooled json encoder goos: linux goarch: amd64 pkg: log/slog/internal/benchmarks cpu: 12th Gen Intel(R) Core(TM) i7-1260P │ old.txt │ new.txt │ │ sec/op │ sec/op vs base │ Attrs/JSON_discard/5_args-16 217.4n ± 8% 217.7n ± 5% ~ (p=0.971 n=10) Attrs/JSON_discard/5_args_ctx-16 217.8n ± 8% 219.0n ± 6% ~ (p=0.723 n=10) Attrs/JSON_discard/10_args-16 482.8n ± 4% 418.5n ± 1% -13.33% (p=0.000 n=10) Attrs/JSON_discard/40_args-16 1.709µ ± 1% 1.413µ ± 1% -17.33% (p=0.000 n=10) geomean 444.5n 409.7n -7.84% │ old.txt │ new.txt │ │ B/op │ B/op vs base │ Attrs/JSON_discard/5_args-16 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ Attrs/JSON_discard/5_args_ctx-16 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ Attrs/JSON_discard/10_args-16 498.0 ± 0% 273.0 ± 0% -45.18% (p=0.000 n=10) Attrs/JSON_discard/40_args-16 2.383Ki ± 0% 1.614Ki ± 0% -32.25% (p=0.000 n=10) geomean ² -21.94% ² ¹ all samples are equal ² summaries must be >0 to compute geomean │ old.txt │ new.txt │ │ allocs/op │ allocs/op vs base │ Attrs/JSON_discard/5_args-16 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ Attrs/JSON_discard/5_args_ctx-16 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ Attrs/JSON_discard/10_args-16 7.000 ± 0% 3.000 ± 0% -57.14% (p=0.000 n=10) Attrs/JSON_discard/40_args-16 22.000 ± 0% 8.000 ± 0% -63.64% (p=0.000 n=10) geomean ² -37.17% ² ¹ all samples are equal ² summaries must be >0 to compute geomean Fixes #74645 Change-Id: I185667cd6caa6a8251e75233eb659c1fd449deaa Reviewed-on: https://go-review.googlesource.com/c/go/+/705555 LUCI-TryBot-Result: Go LUCI Reviewed-by: Jonathan Amsterdam Reviewed-by: Michael Knyszek --- diff --git a/src/log/slog/internal/benchmarks/benchmarks.go b/src/log/slog/internal/benchmarks/benchmarks.go index 3a28523beb..a94ecfa743 100644 --- a/src/log/slog/internal/benchmarks/benchmarks.go +++ b/src/log/slog/internal/benchmarks/benchmarks.go @@ -31,12 +31,19 @@ import ( const testMessage = "Test logging, but use a somewhat realistic message length." +type event struct { + ID string + Index int + Flag bool +} + var ( testTime = time.Date(2022, time.May, 1, 0, 0, 0, 0, time.UTC) testString = "7e3b3b2aaeff56a7108fe11e154200dd/7819479873059528190" testInt = 32768 testDuration = 23 * time.Second testError = errors.New("fail") + testEvent = event{"abcdefgh", 65536, true} ) var testAttrs = []slog.Attr{ diff --git a/src/log/slog/internal/benchmarks/benchmarks_test.go b/src/log/slog/internal/benchmarks/benchmarks_test.go index 18643b73e6..3fec261279 100644 --- a/src/log/slog/internal/benchmarks/benchmarks_test.go +++ b/src/log/slog/internal/benchmarks/benchmarks_test.go @@ -80,12 +80,12 @@ func BenchmarkAttrs(b *testing.B) { slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), ) }, }, @@ -103,37 +103,37 @@ func BenchmarkAttrs(b *testing.B) { slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), slog.String("string", testString), slog.Int("status", testInt), slog.Duration("duration", testDuration), slog.Time("time", testTime), - slog.Any("error", testError), + slog.Any("event", testEvent), ) }, }, diff --git a/src/log/slog/json_handler.go b/src/log/slog/json_handler.go index f139c54139..9c7045cda9 100644 --- a/src/log/slog/json_handler.go +++ b/src/log/slog/json_handler.go @@ -137,15 +137,40 @@ func appendJSONValue(s *handleState, v Value) error { return nil } -func appendJSONMarshal(buf *buffer.Buffer, v any) error { +type jsonEncoder struct { + buf *bytes.Buffer // Use a json.Encoder to avoid escaping HTML. - var bb bytes.Buffer - enc := json.NewEncoder(&bb) - enc.SetEscapeHTML(false) - if err := enc.Encode(v); err != nil { + json *json.Encoder +} + +var jsonEncoderPool = &sync.Pool{ + New: func() any { + enc := &jsonEncoder{ + buf: new(bytes.Buffer), + } + enc.json = json.NewEncoder(enc.buf) + enc.json.SetEscapeHTML(false) + return enc + }, +} + +func appendJSONMarshal(buf *buffer.Buffer, v any) error { + j := jsonEncoderPool.Get().(*jsonEncoder) + defer func() { + // To reduce peak allocation, return only smaller buffers to the pool. + const maxBufferSize = 16 << 10 + if j.buf.Cap() > maxBufferSize { + return + } + j.buf.Reset() + jsonEncoderPool.Put(j) + }() + + if err := j.json.Encode(v); err != nil { return err } - bs := bb.Bytes() + + bs := j.buf.Bytes() buf.Write(bs[:len(bs)-1]) // remove final newline return nil } diff --git a/src/log/slog/json_handler_test.go b/src/log/slog/json_handler_test.go index 65130f2426..fd6b2e39d4 100644 --- a/src/log/slog/json_handler_test.go +++ b/src/log/slog/json_handler_test.go @@ -142,6 +142,39 @@ func jsonValueString(v Value) string { return string(buf) } +func TestJSONAllocs(t *testing.T) { + ctx := t.Context() + l := New(NewJSONHandler(io.Discard, &HandlerOptions{})) + testErr := errors.New("an error occurred") + testEvent := struct { + ID int + Scope string + Enabled bool + }{ + 123456, "abcdefgh", true, + } + + t.Run("message", func(t *testing.T) { + wantAllocs(t, 0, func() { + l.LogAttrs(ctx, LevelInfo, + "hello world", + ) + }) + }) + t.Run("attrs", func(t *testing.T) { + wantAllocs(t, 1, func() { + l.LogAttrs(ctx, LevelInfo, + "hello world", + String("component", "subtest"), + Int("id", 67890), + Bool("flag", true), + Any("error", testErr), + Any("event", testEvent), + ) + }) + }) +} + func BenchmarkJSONHandler(b *testing.B) { for _, bench := range []struct { name string