Skip to content

Commit bec12f1

Browse files
Aoangjba
authored andcommitted
log/slog: optimize appendKey to reduce allocations
This change introduces a new method, `appendTwoStrings`, which optimizes the `appendKey` function by avoiding the allocation of a temporary string (string concatenation of prefix and key). Instead, it directly appends the prefix and key to the buffer. Additionally, added `BenchmarkAppendKey` benchmark tests to validate performance improvements. This change improves performance in cases where large prefixes are used, as verified by the following benchmarks: goos: darwin goarch: arm64 pkg: log/slog cpu: Apple M1 Max │ old.out │ new.out │ │ sec/op │ sec/op vs base │ AppendKey/prefix_size_5-10 44.41n ± 0% 35.62n ± 0% -19.80% (p=0.000 n=10) AppendKey/prefix_size_10-10 48.17n ± 0% 39.12n ± 0% -18.80% (p=0.000 n=10) AppendKey/prefix_size_30-10 84.50n ± 0% 62.30n ± 0% -26.28% (p=0.000 n=10) AppendKey/prefix_size_50-10 124.9n ± 0% 102.3n ± 0% -18.09% (p=0.000 n=10) AppendKey/prefix_size_100-10 203.6n ± 1% 168.7n ± 0% -17.14% (p=0.000 n=10) geomean 85.61n 68.41n -20.09% │ old.out │ new.out │ │ B/op │ B/op vs base │ AppendKey/prefix_size_5-10 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ AppendKey/prefix_size_10-10 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ AppendKey/prefix_size_30-10 48.00 ± 0% 0.00 ± 0% -100.00% (p=0.000 n=10) AppendKey/prefix_size_50-10 128.00 ± 0% 64.00 ± 0% -50.00% (p=0.000 n=10) AppendKey/prefix_size_100-10 224.0 ± 0% 112.0 ± 0% -50.00% (p=0.000 n=10) geomean ² ? ² ³ ¹ all samples are equal ² summaries must be >0 to compute geomean ³ ratios must be >0 to compute geomean │ old.out │ new.out │ │ allocs/op │ allocs/op vs base │ AppendKey/prefix_size_5-10 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ AppendKey/prefix_size_10-10 0.000 ± 0% 0.000 ± 0% ~ (p=1.000 n=10) ¹ AppendKey/prefix_size_30-10 1.000 ± 0% 0.000 ± 0% -100.00% (p=0.000 n=10) AppendKey/prefix_size_50-10 2.000 ± 0% 1.000 ± 0% -50.00% (p=0.000 n=10) AppendKey/prefix_size_100-10 2.000 ± 0% 1.000 ± 0% -50.00% (p=0.000 n=10) geomean ² ? ² ³ ¹ all samples are equal ² summaries must be >0 to compute geomean ³ ratios must be >0 to compute geomean This patch improves performance without altering the external behavior of the `slog` package. Change-Id: I8b47718de522196f06e0ddac48af73e352d2e5cd Reviewed-on: https://go-review.googlesource.com/c/go/+/631415 Reviewed-by: Alan Donovan <[email protected]> Reviewed-by: Jonathan Amsterdam <[email protected]> LUCI-TryBot-Result: Go LUCI <[email protected]>
1 parent 7e8cead commit bec12f1

File tree

2 files changed

+63
-2
lines changed

2 files changed

+63
-2
lines changed

src/log/slog/handler.go

+19-2
Original file line numberDiff line numberDiff line change
@@ -525,8 +525,7 @@ func (s *handleState) appendError(err error) {
525525
func (s *handleState) appendKey(key string) {
526526
s.buf.WriteString(s.sep)
527527
if s.prefix != nil && len(*s.prefix) > 0 {
528-
// TODO: optimize by avoiding allocation.
529-
s.appendString(string(*s.prefix) + key)
528+
s.appendTwoStrings(string(*s.prefix), key)
530529
} else {
531530
s.appendString(key)
532531
}
@@ -538,6 +537,24 @@ func (s *handleState) appendKey(key string) {
538537
s.sep = s.h.attrSep()
539538
}
540539

540+
// appendTwoStrings implements appendString(prefix + key), but faster.
541+
func (s *handleState) appendTwoStrings(x, y string) {
542+
buf := *s.buf
543+
switch {
544+
case s.h.json:
545+
buf.WriteByte('"')
546+
buf = appendEscapedJSONString(buf, x)
547+
buf = appendEscapedJSONString(buf, y)
548+
buf.WriteByte('"')
549+
case !needsQuoting(x) && !needsQuoting(y):
550+
buf.WriteString(x)
551+
buf.WriteString(y)
552+
default:
553+
buf = strconv.AppendQuote(buf, x+y)
554+
}
555+
*s.buf = buf
556+
}
557+
541558
func (s *handleState) appendString(str string) {
542559
if s.h.json {
543560
s.buf.WriteByte('"')

src/log/slog/handler_test.go

+44
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,9 @@ import (
1010
"bytes"
1111
"context"
1212
"encoding/json"
13+
"fmt"
1314
"io"
15+
"log/slog/internal/buffer"
1416
"os"
1517
"path/filepath"
1618
"slices"
@@ -529,6 +531,20 @@ func TestJSONAndTextHandlers(t *testing.T) {
529531
wantText: "name.first=Perry name.last=Platypus",
530532
wantJSON: `{"name":{"first":"Perry","last":"Platypus"}}`,
531533
},
534+
{
535+
name: "group and key (or both) needs quoting",
536+
replace: removeKeys(TimeKey, LevelKey),
537+
attrs: []Attr{
538+
Group("prefix",
539+
String(" needs quoting ", "v"), String("NotNeedsQuoting", "v"),
540+
),
541+
Group("prefix needs quoting",
542+
String(" needs quoting ", "v"), String("NotNeedsQuoting", "v"),
543+
),
544+
},
545+
wantText: `msg=message "prefix. needs quoting "=v prefix.NotNeedsQuoting=v "prefix needs quoting. needs quoting "=v "prefix needs quoting.NotNeedsQuoting"=v`,
546+
wantJSON: `{"msg":"message","prefix":{" needs quoting ":"v","NotNeedsQuoting":"v"},"prefix needs quoting":{" needs quoting ":"v","NotNeedsQuoting":"v"}}`,
547+
},
532548
} {
533549
r := NewRecord(testTime, LevelInfo, "message", callerPC(2))
534550
line := strconv.Itoa(r.source().Line)
@@ -732,3 +748,31 @@ func TestDiscardHandler(t *testing.T) {
732748
l.Info("info", "a", []Attr{Int("i", 1)})
733749
l.Info("info", "a", GroupValue(Int("i", 1)))
734750
}
751+
752+
func BenchmarkAppendKey(b *testing.B) {
753+
for _, size := range []int{5, 10, 30, 50, 100} {
754+
for _, quoting := range []string{"no_quoting", "pre_quoting", "key_quoting", "both_quoting"} {
755+
b.Run(fmt.Sprintf("%s_prefix_size_%d", quoting, size), func(b *testing.B) {
756+
var (
757+
hs = NewJSONHandler(io.Discard, nil).newHandleState(buffer.New(), false, "")
758+
prefix = bytes.Repeat([]byte("x"), size)
759+
key = "key"
760+
)
761+
762+
if quoting == "pre_quoting" || quoting == "both_quoting" {
763+
prefix[0] = '"'
764+
}
765+
if quoting == "key_quoting" || quoting == "both_quoting" {
766+
key = "ke\""
767+
}
768+
769+
hs.prefix = (*buffer.Buffer)(&prefix)
770+
771+
for b.Loop() {
772+
hs.appendKey(key)
773+
hs.buf.Reset()
774+
}
775+
})
776+
}
777+
}
778+
}

0 commit comments

Comments
 (0)