Skip to content

Commit afdae99

Browse files
committed
perf(log/slog): reduce allocs on Any value handling
It reduce allocs of Any values handling by reusing the JSON Encoder and using `fmt.Fprint` instead of `fmt.Sprint` for value formatting. Solves: #74645
1 parent 385000b commit afdae99

File tree

7 files changed

+168
-29
lines changed

7 files changed

+168
-29
lines changed

src/log/slog/encoder.go

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
1+
// Copyright 2022 The Go Authors. All rights reserved.
2+
// Use of this source code is governed by a BSD-style
3+
// license that can be found in the LICENSE file.
4+
5+
package slog
6+
7+
type encoder interface {
8+
reset()
9+
free()
10+
encode(v any) error
11+
bytes() []byte
12+
}

src/log/slog/handler.go

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -380,12 +380,13 @@ func (h *commonHandler) attrSep() string {
380380
// The initial value of sep determines whether to emit a separator
381381
// before the next key, after which it stays true.
382382
type handleState struct {
383-
h *commonHandler
384-
buf *buffer.Buffer
385-
freeBuf bool // should buf be freed?
386-
sep string // separator to write before next key
387-
prefix *buffer.Buffer // for text: key prefix
388-
groups *[]string // pool-allocated slice of active groups, for ReplaceAttr
383+
h *commonHandler
384+
buf *buffer.Buffer
385+
freeBuf bool // should buf be freed?
386+
sep string // separator to write before next key
387+
prefix *buffer.Buffer // for text: key prefix
388+
groups *[]string // pool-allocated slice of active groups, for ReplaceAttr
389+
anyEncoder encoder
389390
}
390391

391392
var groupPool = sync.Pool{New: func() any {
@@ -416,6 +417,10 @@ func (s *handleState) free() {
416417
*gs = (*gs)[:0]
417418
groupPool.Put(gs)
418419
}
420+
if s.anyEncoder != nil {
421+
s.anyEncoder.free()
422+
s.anyEncoder = nil
423+
}
419424
s.prefix.Free()
420425
}
421426

@@ -558,7 +563,7 @@ func (s *handleState) appendTwoStrings(x, y string) {
558563
buf = appendEscapedJSONString(buf, x)
559564
buf = appendEscapedJSONString(buf, y)
560565
buf.WriteByte('"')
561-
case !needsQuoting(x) && !needsQuoting(y):
566+
case !needsQuotingString(x) && !needsQuotingString(y):
562567
buf.WriteString(x)
563568
buf.WriteString(y)
564569
default:
@@ -574,7 +579,7 @@ func (s *handleState) appendString(str string) {
574579
s.buf.WriteByte('"')
575580
} else {
576581
// text
577-
if needsQuoting(str) {
582+
if needsQuotingString(str) {
578583
*s.buf = strconv.AppendQuote(*s.buf, str)
579584
} else {
580585
s.buf.WriteString(str)

src/log/slog/internal/benchmarks/benchmarks.go

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,11 @@ var (
3737
testInt = 32768
3838
testDuration = 23 * time.Second
3939
testError = errors.New("fail")
40+
testEvent = &event{
41+
ID: "testing_event_#01",
42+
Description: "Some text for this description to simulate a real scenario.",
43+
CreatedAt: time.Date(2025, time.July, 5, 0, 0, 0, 0, time.UTC),
44+
}
4045
)
4146

4247
var testAttrs = []slog.Attr{
@@ -48,3 +53,9 @@ var testAttrs = []slog.Attr{
4853
}
4954

5055
const wantText = "time=1651363200 level=0 msg=Test logging, but use a somewhat realistic message length. string=7e3b3b2aaeff56a7108fe11e154200dd/7819479873059528190 status=32768 duration=23000000000 time=1651363200 error=fail\n"
56+
57+
type event struct {
58+
ID string `json:"id"`
59+
Description string `json:"description"`
60+
CreatedAt time.Time `json:"created_at"`
61+
}

src/log/slog/internal/benchmarks/benchmarks_test.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -85,7 +85,7 @@ func BenchmarkAttrs(b *testing.B) {
8585
slog.Int("status", testInt),
8686
slog.Duration("duration", testDuration),
8787
slog.Time("time", testTime),
88-
slog.Any("error", testError),
88+
slog.Any("event", testEvent),
8989
)
9090
},
9191
},
@@ -133,7 +133,7 @@ func BenchmarkAttrs(b *testing.B) {
133133
slog.Int("status", testInt),
134134
slog.Duration("duration", testDuration),
135135
slog.Time("time", testTime),
136-
slog.Any("error", testError),
136+
slog.Any("event", testEvent),
137137
)
138138
},
139139
},

src/log/slog/json_handler.go

Lines changed: 54 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,6 @@ import (
1111
"errors"
1212
"fmt"
1313
"io"
14-
"log/slog/internal/buffer"
1514
"strconv"
1615
"sync"
1716
"time"
@@ -113,7 +112,7 @@ func appendJSONValue(s *handleState, v Value) error {
113112
// json.Marshal is funny about floats; it doesn't
114113
// always match strconv.AppendFloat. So just call it.
115114
// That's expensive, but floats are rare.
116-
if err := appendJSONMarshal(s.buf, v.Float64()); err != nil {
115+
if err := appendJSONMarshal(s, v.Float64()); err != nil {
117116
return err
118117
}
119118
case KindBool:
@@ -129,27 +128,71 @@ func appendJSONValue(s *handleState, v Value) error {
129128
if err, ok := a.(error); ok && !jm {
130129
s.appendString(err.Error())
131130
} else {
132-
return appendJSONMarshal(s.buf, a)
131+
return appendJSONMarshal(s, a)
133132
}
134133
default:
135134
panic(fmt.Sprintf("bad kind: %s", v.Kind()))
136135
}
137136
return nil
138137
}
139138

140-
func appendJSONMarshal(buf *buffer.Buffer, v any) error {
141-
// Use a json.Encoder to avoid escaping HTML.
142-
var bb bytes.Buffer
143-
enc := json.NewEncoder(&bb)
144-
enc.SetEscapeHTML(false)
145-
if err := enc.Encode(v); err != nil {
139+
func appendJSONMarshal(s *handleState, v any) error {
140+
// Aquire a new encoder if not asigned.
141+
if s.anyEncoder == nil {
142+
s.anyEncoder = newJSONMarshalEncoder()
143+
}
144+
145+
enc := s.anyEncoder
146+
enc.reset() // reset the encoder, if was reused
147+
if err := enc.encode(v); err != nil {
146148
return err
147149
}
148-
bs := bb.Bytes()
149-
buf.Write(bs[:len(bs)-1]) // remove final newline
150+
151+
bs := enc.bytes()
152+
s.buf.Write(bs[:len(bs)-1]) // remove final newline
150153
return nil
151154
}
152155

156+
type jsonMarshalEncoder struct {
157+
buf *bytes.Buffer
158+
enc *json.Encoder
159+
}
160+
161+
func newJSONMarshalEncoder() encoder {
162+
if enc := jsonEncoderPool.Get(); enc != nil {
163+
return enc.(*jsonMarshalEncoder)
164+
}
165+
166+
buf := &bytes.Buffer{}
167+
168+
// Use a json.Encoder to avoid escaping HTML.
169+
jsonEnc := json.NewEncoder(buf)
170+
jsonEnc.SetEscapeHTML(false)
171+
172+
return &jsonMarshalEncoder{buf: buf, enc: jsonEnc}
173+
}
174+
175+
func (e *jsonMarshalEncoder) reset() {
176+
e.buf.Reset()
177+
}
178+
179+
func (e *jsonMarshalEncoder) encode(v any) error {
180+
return e.enc.Encode(v)
181+
}
182+
183+
func (e *jsonMarshalEncoder) bytes() []byte {
184+
return e.buf.Bytes()
185+
}
186+
187+
func (e *jsonMarshalEncoder) free() {
188+
const maxBufferSize = 8 << 10
189+
if e.buf.Cap() <= maxBufferSize {
190+
jsonEncoderPool.Put(e)
191+
}
192+
}
193+
194+
var jsonEncoderPool = sync.Pool{}
195+
153196
// appendEscapedJSONString escapes s for JSON and appends it to buf.
154197
// It does not surround the string in quotation marks.
155198
//

src/log/slog/text_handler.go

Lines changed: 69 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
package slog
66

77
import (
8+
"bytes"
89
"context"
910
"encoding"
1011
"fmt"
@@ -114,7 +115,21 @@ func appendTextValue(s *handleState, v Value) error {
114115
s.buf.WriteString(strconv.Quote(string(bs)))
115116
return nil
116117
}
117-
s.appendString(fmt.Sprintf("%+v", v.Any()))
118+
if s.anyEncoder == nil {
119+
s.anyEncoder = newTextMarshalEncoder()
120+
}
121+
122+
enc := s.anyEncoder
123+
enc.reset()
124+
enc.encode(v.Any())
125+
bs := enc.bytes()
126+
if needsQuotingBytes(bs) {
127+
s.buf.WriteByte('"')
128+
s.buf.Write(bs)
129+
s.buf.WriteByte('"')
130+
return nil
131+
}
132+
s.buf.Write(bs)
118133
default:
119134
*s.buf = v.append(*s.buf)
120135
}
@@ -136,12 +151,60 @@ func byteSlice(a any) ([]byte, bool) {
136151
return nil, false
137152
}
138153

139-
func needsQuoting(s string) bool {
140-
if len(s) == 0 {
154+
type textMarshalEncoder struct {
155+
buf *bytes.Buffer
156+
}
157+
158+
func newTextMarshalEncoder() encoder {
159+
if enc := textEncoderPool.Get(); enc != nil {
160+
return enc.(*textMarshalEncoder)
161+
}
162+
163+
buf := &bytes.Buffer{}
164+
165+
return &textMarshalEncoder{buf: buf}
166+
}
167+
168+
func (e *textMarshalEncoder) reset() {
169+
e.buf.Reset()
170+
}
171+
172+
func (e *textMarshalEncoder) encode(v any) error {
173+
fmt.Fprintf(e.buf, "%+v", v)
174+
return nil
175+
}
176+
177+
func (e *textMarshalEncoder) bytes() []byte {
178+
return e.buf.Bytes()
179+
}
180+
181+
func (e *textMarshalEncoder) free() {
182+
const maxBufferSize = 4 << 10
183+
if e.buf.Cap() <= maxBufferSize {
184+
textEncoderPool.Put(e)
185+
}
186+
}
187+
188+
var textEncoderPool = sync.Pool{}
189+
190+
func needsQuotingString(s string) bool {
191+
return needsQuoting(s, func(i int) (rune, int) {
192+
return utf8.DecodeRuneInString(s[i:])
193+
})
194+
}
195+
196+
func needsQuotingBytes(b []byte) bool {
197+
return needsQuoting(b, func(i int) (rune, int) {
198+
return utf8.DecodeRune(b[i:])
199+
})
200+
}
201+
202+
func needsQuoting[T string | []byte](text T, decodeRune func(i int) (rune, int)) bool {
203+
if len(text) == 0 {
141204
return true
142205
}
143-
for i := 0; i < len(s); {
144-
b := s[i]
206+
for i := 0; i < len(text); {
207+
b := text[i]
145208
if b < utf8.RuneSelf {
146209
// Quote anything except a backslash that would need quoting in a
147210
// JSON string, as well as space and '='
@@ -151,7 +214,7 @@ func needsQuoting(s string) bool {
151214
i++
152215
continue
153216
}
154-
r, size := utf8.DecodeRuneInString(s[i:])
217+
r, size := decodeRune(i)
155218
if r == utf8.RuneError || unicode.IsSpace(r) || !unicode.IsPrint(r) {
156219
return true
157220
}

src/log/slog/text_handler_test.go

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -168,9 +168,14 @@ func TestNeedsQuoting(t *testing.T) {
168168
{"a b", true},
169169
{"badutf8\xF6", true},
170170
} {
171-
got := needsQuoting(test.in)
171+
got := needsQuotingString(test.in)
172172
if got != test.want {
173-
t.Errorf("%q: got %t, want %t", test.in, got, test.want)
173+
t.Errorf("needsQuotingString: %q: got %t, want %t", test.in, got, test.want)
174+
}
175+
176+
got = needsQuotingBytes([]byte(test.in))
177+
if got != test.want {
178+
t.Errorf("needsQuotingBytes: %q: got %t, want %t", test.in, got, test.want)
174179
}
175180
}
176181
}

0 commit comments

Comments
 (0)