Golang proposal: log/slog: improve performance by reducing allocs in encoding Any values.

Proposal Details

The current implementation of the log/slog package can be improved by optimizing how values are encoded in both the JSONHandler and TextHandler.

Observations

• In JSONHandler, encoding Any values creates a new json.Encoder instance every time. This can introduce unnecessary allocations and reduce performance, especially under heavy logging.
• In TextHandler, the current approach to formatting values could be improved by using fmt.Fprint instead of intermediate string formatting, which tends to allocate more.

Suggested Improvements

1. Use a sync.Pool to reuse encoders for both JSONHandler and TextHandler when encoding Any values, reducing the number of allocations and improving throughput.
2. In the AnyEncoder implementation of the TextHandler, use fmt.Fprint instead of fmt.Sprint.

Benchstats results

For the TextHandler, we observed up to a 21% performance improvement, and for the JSONHandler, up to a 14% improvement. Regarding allocations, there were more than 50% fewer allocations in cases involving Any types.

goos: darwin
goarch: arm64
pkg: log/slog/internal/benchmarks
cpu: Apple M1 Max
                                     │ golden.txt  │               new.text               │
                                     │   sec/op    │    sec/op     vs base                │
Attrs/fastText_discard/5_args-10       46.66n ± 6%   47.66n ±  5%        ~ (p=0.280 n=10)
Attrs/fastText_discard/5_args_ctx-10   48.32n ± 7%   47.45n ±  3%        ~ (p=0.280 n=10)
Attrs/fastText_discard/10_args-10      265.1n ± 1%   267.8n ±  5%        ~ (p=0.468 n=10)
Attrs/fastText_discard/40_args-10      755.5n ± 0%   754.5n ±  0%   -0.13% (p=0.030 n=10)
Attrs/Text_discard/5_args-10           284.5n ± 4%   298.7n ±  7%        ~ (p=0.218 n=10)
Attrs/Text_discard/5_args_ctx-10       289.1n ± 4%   302.0n ±  4%   +4.48% (p=0.004 n=10)
Attrs/Text_discard/10_args-10          586.0n ± 1%   462.3n ±  0%  -21.11% (p=0.000 n=10)
Attrs/Text_discard/40_args-10          1.466µ ± 0%   1.320µ ±  0%   -9.96% (p=0.000 n=10)
Attrs/JSON_discard/5_args-10           256.1n ± 3%   262.9n ± 17%        ~ (p=0.280 n=10)
Attrs/JSON_discard/5_args_ctx-10       265.8n ± 5%   266.3n ±  6%        ~ (p=0.971 n=10)
Attrs/JSON_discard/10_args-10          507.2n ± 1%   435.8n ±  2%  -14.08% (p=0.000 n=10)
Attrs/JSON_discard/40_args-10          1.299µ ± 1%   1.232µ ±  1%   -5.20% (p=0.000 n=10)
geomean                                325.8n        314.7n         -3.40%

                                     │   golden.txt   │                 new.text                  │
                                     │      B/op      │     B/op      vs base                     │
Attrs/fastText_discard/5_args-10         0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/5_args_ctx-10     0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/10_args-10        361.0 ± 0%       361.0 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/40_args-10      1.534Ki ± 0%     1.534Ki ± 0%         ~ (p=1.000 n=10)
Attrs/Text_discard/5_args-10             4.000 ± 0%       0.000 ± 0%  -100.00% (p=0.000 n=10)
Attrs/Text_discard/5_args_ctx-10         4.000 ± 0%       0.000 ± 0%  -100.00% (p=0.000 n=10)
Attrs/Text_discard/10_args-10            509.0 ± 0%       361.0 ± 0%   -29.08% (p=0.000 n=10)
Attrs/Text_discard/40_args-10          1.700Ki ± 0%     1.534Ki ± 0%    -9.79% (p=0.000 n=10)
Attrs/JSON_discard/5_args-10             0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/JSON_discard/5_args_ctx-10         0.000 ± 0%       0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/JSON_discard/10_args-10            449.0 ± 0%       257.0 ± 0%   -42.76% (p=0.000 n=10)
Attrs/JSON_discard/40_args-10          1.618Ki ± 0%     1.432Ki ± 0%   -11.53% (p=0.000 n=10)
geomean                                             ²                 ?                       ² ³
¹ all samples are equal
² summaries must be >0 to compute geomean
³ ratios must be >0 to compute geomean

                                     │  golden.txt   │                new.text                 │
                                     │   allocs/op   │ allocs/op   vs base                     │
Attrs/fastText_discard/5_args-10        0.000 ± 0%     0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/5_args_ctx-10    0.000 ± 0%     0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/10_args-10       6.000 ± 0%     6.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/fastText_discard/40_args-10       6.000 ± 0%     6.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/Text_discard/5_args-10            1.000 ± 0%     0.000 ± 0%  -100.00% (p=0.000 n=10)
Attrs/Text_discard/5_args_ctx-10        1.000 ± 0%     0.000 ± 0%  -100.00% (p=0.000 n=10)
Attrs/Text_discard/10_args-10           8.000 ± 0%     6.000 ± 0%   -25.00% (p=0.000 n=10)
Attrs/Text_discard/40_args-10          14.000 ± 0%     6.000 ± 0%   -57.14% (p=0.000 n=10)
Attrs/JSON_discard/5_args-10            0.000 ± 0%     0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/JSON_discard/5_args_ctx-10        0.000 ± 0%     0.000 ± 0%         ~ (p=1.000 n=10) ¹
Attrs/JSON_discard/10_args-10           4.000 ± 0%     2.000 ± 0%   -50.00% (p=0.000 n=10)
Attrs/JSON_discard/40_args-10           4.000 ± 0%     2.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

Comment From: gabyhelp

Related Issues

• encoding/json: optimize field sorting with slices and cmp #67046 (closed)
• proposal: log/slog: copy Logger by value instead of pointer #59126 (closed)
• encoding/json: optimize tag parsing by introducing cutTag helper function #67100

Related Code Changes

• encoding/json: optimize field sorting with slices and cmp
• log/slog: optimize appendKey to reduce allocations
• runtime: intern some small strings
• encoding/json: consolidate the isSpace function
• log: make use of fmt.Append functionality
• encoding/json: don't reset before returning buffer to pool
• encoding/json: do not fill d.errorContext until deemed necessary

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

Comment From: gopherbot

Change https://go.dev/cl/688455 mentions this issue: log/slog: reduce allocs on Any value handling