WIP: log values from context
Having to add a modified logger to a context when adding some values to the context which are meant to be logged (like trace ID) has two drawbacks:
- the instrumentation code which adds the values to the context must be aware of logging
- modifying the logger incurs a cost, whether some actual log entry then gets emitted or not.
A better approach is to add the values only to the context, then during logging extract them. This is the same approach that contextual logging in Go is going to use.
I have experimented with a few different approaches for this, including doing it entirely in klog by wrapping the LogSink in a logger with one that injects the extra values. That is complicated and not worth discussing further.
In logr itself there are different approaches - see individual commits in https://github.com/pohly/logr/commits/with-context-all
The one proposed here implements logging of the additional values in Logger (no need to modify LogSinks) and passes them to the LogSink via WithValues.
Here's a comparison of all benchmarks between master (b3dc695bce6838cb3f27ac700c1017947bc3235b) and this PR:
name old time/op new time/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 95.6ns ± 4% 99.7ns ± 4% +4.31% (p=0.032 n=5+5)
DiscardLogInfoSeveralArgs-36 241ns ± 1% 245ns ± 1% +1.56% (p=0.016 n=5+5)
DiscardLogInfoWithValues-36 244ns ± 0% 249ns ± 1% +2.35% (p=0.008 n=5+5)
DiscardLogV0Info-36 242ns ± 1% 252ns ± 1% +4.20% (p=0.008 n=5+5)
DiscardLogV9Info-36 243ns ± 2% 263ns ± 2% +8.03% (p=0.008 n=5+5)
DiscardLogError-36 270ns ± 1% 264ns ± 1% -2.23% (p=0.008 n=5+5)
DiscardWithValues-36 118ns ± 1% 116ns ± 2% -1.90% (p=0.024 n=5+5)
DiscardWithName-36 2.26ns ± 0% 2.29ns ± 0% +1.43% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.19µs ± 1% 2.13µs ± 1% -3.12% (p=0.008 n=5+5)
FuncrJSONLogInfoOneArg-36 2.47µs ± 0% 2.41µs ± 1% -2.68% (p=0.008 n=5+5)
FuncrLogInfoSeveralArgs-36 4.54µs ± 3% 4.52µs ± 3% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.79µs ± 3% 4.80µs ± 3% ~ (p=1.000 n=5+5)
FuncrLogInfoWithValues-36 4.67µs ± 5% 4.59µs ± 1% ~ (p=0.151 n=5+5)
FuncrJSONLogInfoWithValues-36 4.85µs ± 2% 4.80µs ± 4% ~ (p=1.000 n=5+5)
FuncrLogV0Info-36 4.56µs ± 4% 4.49µs ± 3% ~ (p=0.421 n=5+5)
FuncrJSONLogV0Info-36 4.80µs ± 3% 4.77µs ± 3% ~ (p=0.794 n=5+5)
FuncrLogV9Info-36 262ns ± 1% 276ns ± 1% +5.40% (p=0.008 n=5+5)
FuncrJSONLogV9Info-36 259ns ± 1% 276ns ± 1% +6.89% (p=0.008 n=5+5)
FuncrLogError-36 4.89µs ± 3% 4.88µs ± 1% ~ (p=0.841 n=5+5)
FuncrJSONLogError-36 5.13µs ± 2% 5.11µs ± 1% ~ (p=1.000 n=5+5)
FuncrWithValues-36 1.40µs ± 2% 1.26µs ± 4% -9.60% (p=0.008 n=5+5)
FuncrWithName-36 212ns ± 2% 171ns ± 1% -19.41% (p=0.008 n=5+5)
FuncrWithCallDepth-36 210ns ± 0% 176ns ± 1% -15.86% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.64µs ± 1% 2.59µs ± 1% -1.69% (p=0.008 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.66µs ± 2% 2.60µs ± 2% -2.35% (p=0.032 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.64µs ± 2% 2.61µs ± 0% ~ (p=0.095 n=5+5)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 181µs ± 4% 32µs ± 3% -82.48% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 201µs ± 2% 49µs ± 3% -75.73% (p=0.008 n=5+5)
NewContext100Percent-36 532µs ± 2% 540µs ± 2% ~ (p=0.095 n=5+5)
name old alloc/op new alloc/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 328B ± 0% 264B ± 0% -19.51% (p=0.008 n=5+5)
FuncrWithName-36 160B ± 0% 96B ± 0% -40.00% (p=0.008 n=5+5)
FuncrWithCallDepth-36 160B ± 0% 96B ± 0% -40.00% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 49.0kB ± 0% 11.2kB ± 0% -77.14% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 57.3kB ± 0% 19.2kB ± 0% -66.51% (p=0.008 n=5+5)
NewContext100Percent-36 178kB ± 0% 170kB ± 0% ~ (p=0.079 n=4+5)
name old allocs/op new allocs/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 1.01k ± 0% 0.22k ± 0% -78.24% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 1.10k ± 0% 0.30k ± 0% -72.73% (p=0.008 n=5+5)
NewContext100Percent-36 2.10k ± 0% 2.20k ± 0% +4.76% (p=0.008 n=5+5)
I prefer the first model, myself. The main advantage of pushing this down to the Sink is that the ContextKeys don't get copied?
I redid the performance comparison after using the funcr optimization for both and there's no clear winner.
The semantic is slightly different, too, at least in the current implementation. By appending at the end of the Info args, the context overwrites parameters, which feels backwards. If the parameters are malformed (missing key or value), then the context values also don't get logged properly. It might be better to pass them to LogSink.WithValues, but then the performance becomes different again.
So there's a few points to close on:
-
does the cost of Logger getting bigger matter? It's an interface (16 bytes) + pointer (8 bytes). If we push it down to LogSink to store, we avoid that tiny copy on each Info/Error, at the cost of making every sink get an update.
-
what is the "right" semantic - that main() configures this or that code which uses loggers and contexts configure it?
-
should context values come first or last in the list? We could change the append to a prepend, I think?
does the cost of Logger getting bigger matter?
The approach where Logger is smaller is a bit faster in traditional benchmarks that rely on copying Logger and slower in the new benchmarks that use context values:
name old time/op new time/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 108ns ± 3% 104ns ± 3% ~ (p=0.095 n=5+5)
DiscardLogInfoSeveralArgs-36 247ns ± 1% 245ns ± 1% -0.82% (p=0.032 n=5+5)
DiscardLogInfoWithValues-36 249ns ± 0% 244ns ± 1% -1.72% (p=0.008 n=5+5)
DiscardLogV0Info-36 249ns ± 1% 246ns ± 0% -1.17% (p=0.016 n=5+5)
DiscardLogV9Info-36 262ns ± 1% 257ns ± 0% -2.01% (p=0.008 n=5+5)
DiscardLogError-36 278ns ± 1% 261ns ± 0% -5.96% (p=0.008 n=5+5)
DiscardWithValues-36 115ns ± 1% 115ns ± 1% ~ (p=1.000 n=5+5)
DiscardWithName-36 2.42ns ± 0% 2.29ns ± 0% -5.38% (p=0.016 n=4+5)
FuncrLogInfoOneArg-36 2.11µs ± 1% 2.13µs ± 1% ~ (p=0.111 n=5+5)
FuncrJSONLogInfoOneArg-36 2.39µs ± 1% 2.40µs ± 1% ~ (p=0.595 n=5+5)
FuncrLogInfoSeveralArgs-36 4.42µs ± 3% 4.51µs ± 3% ~ (p=0.151 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.86µs ± 1% 4.73µs ± 3% -2.69% (p=0.032 n=5+5)
FuncrLogInfoWithValues-36 4.60µs ± 1% 4.60µs ± 2% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoWithValues-36 4.95µs ± 1% 4.80µs ± 4% ~ (p=0.056 n=5+5)
FuncrLogV0Info-36 4.58µs ± 2% 4.58µs ± 2% ~ (p=1.000 n=5+5)
FuncrJSONLogV0Info-36 4.82µs ± 3% 4.76µs ± 2% ~ (p=0.246 n=5+5)
FuncrLogV9Info-36 278ns ± 2% 273ns ± 1% -1.81% (p=0.016 n=5+5)
FuncrJSONLogV9Info-36 279ns ± 0% 274ns ± 0% -1.87% (p=0.008 n=5+5)
FuncrLogError-36 4.86µs ± 2% 4.80µs ± 1% ~ (p=0.151 n=5+5)
FuncrJSONLogError-36 5.15µs ± 1% 5.10µs ± 1% ~ (p=0.222 n=5+5)
FuncrWithValues-36 1.29µs ± 2% 1.30µs ± 2% ~ (p=0.548 n=5+5)
FuncrWithName-36 172ns ± 1% 172ns ± 1% ~ (p=0.571 n=5+5)
FuncrWithCallDepth-36 175ns ± 1% 174ns ± 1% ~ (p=0.841 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.65µs ± 1% 2.58µs ± 1% -2.73% (p=0.008 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.67µs ± 1% 2.59µs ± 1% -2.89% (p=0.008 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.67µs ± 1% 2.60µs ± 1% -2.59% (p=0.008 n=5+5)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 30.7µs ± 2% 31.3µs ± 2% ~ (p=0.095 n=5+5)
NewContext100PercentDisabled-36 49.3µs ± 1% 50.1µs ± 1% +1.58% (p=0.032 n=5+5)
NewContext100Percent-36 483µs ± 3% 550µs ± 2% +13.96% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 11.1kB ± 0% 11.2kB ± 0% +0.65% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 19.2kB ± 0% 19.2kB ± 0% ~ (all equal)
NewContext100Percent-36 163kB ± 0% 170kB ± 0% +4.41% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 216 ± 0% 220 ± 0% +1.85% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 300 ± 0% 300 ± 0% ~ (all equal)
NewContext100Percent-36 1.80k ± 0% 2.20k ± 0% +22.22% (p=0.008 n=5+5)
Compared to the baseline (= current master), my preferred solution (= Logger.WithContextValues + LogSink.WithValues for the extra values) has this overhead:
name old time/op new time/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 98.9ns ± 2% 109.6ns ± 4% +10.79% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 234ns ± 1% 246ns ± 1% +5.15% (p=0.008 n=5+5)
DiscardLogInfoWithValues-36 236ns ± 1% 249ns ± 1% +5.40% (p=0.008 n=5+5)
DiscardLogV0Info-36 240ns ± 0% 248ns ± 2% +3.25% (p=0.008 n=5+5)
DiscardLogV9Info-36 234ns ± 0% 262ns ± 1% +11.61% (p=0.008 n=5+5)
DiscardLogError-36 266ns ± 1% 279ns ± 1% +5.01% (p=0.008 n=5+5)
DiscardWithValues-36 116ns ± 2% 116ns ± 1% ~ (p=0.286 n=5+5)
DiscardWithName-36 2.25ns ± 1% 2.41ns ± 1% +7.17% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.11µs ± 2% 2.12µs ± 1% ~ (p=0.381 n=5+5)
FuncrJSONLogInfoOneArg-36 2.38µs ± 0% 2.39µs ± 1% ~ (p=0.690 n=5+5)
FuncrLogInfoSeveralArgs-36 4.53µs ± 3% 4.46µs ± 3% ~ (p=0.095 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.74µs ± 3% 4.70µs ± 4% ~ (p=0.690 n=5+5)
FuncrLogInfoWithValues-36 4.56µs ± 1% 4.53µs ± 2% ~ (p=0.421 n=5+5)
FuncrJSONLogInfoWithValues-36 4.80µs ± 2% 4.75µs ± 5% ~ (p=1.000 n=5+5)
FuncrLogV0Info-36 4.49µs ± 1% 4.51µs ± 1% ~ (p=0.548 n=5+5)
FuncrJSONLogV0Info-36 4.71µs ± 3% 4.83µs ± 2% ~ (p=0.056 n=5+5)
FuncrLogV9Info-36 249ns ± 1% 279ns ± 1% +11.79% (p=0.008 n=5+5)
FuncrJSONLogV9Info-36 249ns ± 0% 281ns ± 1% +12.79% (p=0.008 n=5+5)
FuncrLogError-36 4.74µs ± 3% 4.85µs ± 5% ~ (p=0.151 n=5+5)
FuncrJSONLogError-36 5.04µs ± 1% 5.09µs ± 3% ~ (p=0.548 n=5+5)
FuncrWithValues-36 1.30µs ± 3% 1.29µs ± 1% ~ (p=1.000 n=5+5)
FuncrWithName-36 173ns ± 1% 174ns ± 1% ~ (p=0.151 n=5+5)
FuncrWithCallDepth-36 170ns ± 1% 178ns ± 2% +4.60% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.56µs ± 3% 2.68µs ± 1% +4.50% (p=0.008 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.59µs ± 1% 2.67µs ± 1% +3.13% (p=0.008 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.62µs ± 2% 2.68µs ± 1% +2.25% (p=0.008 n=5+5)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 175µs ± 5% 31µs ± 2% -82.28% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 188µs ± 3% 49µs ± 2% -73.82% (p=0.008 n=5+5)
NewContext100Percent-36 517µs ± 3% 512µs ± 3% ~ (p=0.222 n=5+5)
name old alloc/op new alloc/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 42.6kB ± 0% 11.2kB ± 0% -73.78% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 50.9kB ± 0% 19.2kB ± 0% -62.30% (p=0.008 n=5+5)
NewContext100Percent-36 171kB ± 0% 167kB ± 0% -2.34% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
pkg:github.com/go-logr/logr/benchmark goos:linux goarch:amd64
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
pkg:github.com/go-logr/logr/examples/benchmarks goos:linux goarch:amd64
NewContext1Percent-36 1.01k ± 0% 0.22k ± 0% -78.34% (p=0.008 n=5+5)
NewContext100PercentDisabled-36 1.10k ± 0% 0.30k ± 0% -72.73% (p=0.008 n=5+5)
NewContext100Percent-36 2.10k ± 0% 2.10k ± 0% ~ (all equal)
I think it's acceptable.
what is the "right" semantic - that main() configures this or that code which uses loggers and contexts configure it?
There's probably not a single "right" solution, but the one where both works is more flexible.
should context values come first or last in the list? We could change the append to a prepend, I think?
I prefer WithValues - see my arguments above and in the new commit message for the variant of the Logger implementation.
I force-pushed with the changes discussed above and also added one new commit for Discard: it might be useful to keep it unchanged also when WithContext and WithContextValues are called for it.
I have added several commits at the end to support logging of context values with helper functions. I'll continue with performance investigations. As it stands now, this API is sufficient for the original goal (logging of OpenTelemetry span and trace ID, see https://github.com/kubernetes/kubernetes/pull/114088).
This PR now carries multiple ideas, which probably deserve their own PRs to consider.
Yes, it has become my playground for everything that might change the logr API because it isn't clear yet how much of that is related. This will have to be sorted out.
I don't love the name. I thought PseudoStruct was a cute name, but maybe too cute.
Perhaps Object?
This starts to feel like a poor-man's version of slog Attr - should we borrow some aspects of that to make eventual transitions a bit easier?
I'll check.
We should consider Logger.CanX() methods
As replacement for casting the sink? Does that mean that CanX returns bool or the specialized LogSink? The usage is not clear to me.
I think I have found an approach that minimizes the size of Logger and allows caching of the context retrieval + WithValues - see the last two commits. Performance seems okay, but at the cost of increased complexity.
I removed the KeysAndValues type from this PR, it's not needed here.
I cleaned up the PR and probably would not squash it further because each commit explains why a change is done.
WRT squash, I'd probably just elide the imtermediate state, something like:
- funcr Options optimzation
- all Discard() related changes
- add benchmark
- squashed context values + funcs
- struct optimzation
- cache
Even 3 and 4 could probably squash, but not a huge deal
DiscardWithName() is suspicious. I'd like to understand that.
This is because of the additional l.sink == discardLogSinkInstance comparion. The test case is so fast at 2.24ns that it matters. DiscardLogError gets a bit faster.
I found that the comparison becomes faster when using &discardLogSink{} as discardLogSinkInstance LogSink instead of discardLogSink{}.
Baseline vs. discardLogSink{}:
DiscardLogInfoOneArg-36 96.6ns ± 2% 102.0ns ± 1% +5.59% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 237ns ± 2% 241ns ± 1% +1.97% (p=0.048 n=5+5)
DiscardLogInfoWithValues-36 241ns ± 1% 238ns ± 1% ~ (p=0.151 n=5+5)
DiscardLogV0Info-36 242ns ± 0% 240ns ± 0% -0.79% (p=0.008 n=5+5)
DiscardLogV9Info-36 239ns ± 2% 240ns ± 1% ~ (p=0.198 n=5+5)
DiscardLogError-36 266ns ± 0% 240ns ± 1% -10.05% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 3% 124ns ± 2% +5.87% (p=0.008 n=5+5)
DiscardWithName-36 2.24ns ± 1% 4.74ns ± 0% +111.23% (p=0.008 n=5+5)
Baseline vs. &discardLogSink{}:
DiscardLogInfoOneArg-36 96.6ns ± 2% 99.3ns ± 3% ~ (p=0.056 n=5+5)
DiscardLogInfoSeveralArgs-36 237ns ± 2% 240ns ± 0% ~ (p=0.079 n=5+5)
DiscardLogInfoWithValues-36 241ns ± 1% 237ns ± 0% -1.58% (p=0.016 n=5+5)
DiscardLogV0Info-36 242ns ± 0% 237ns ± 1% -1.69% (p=0.008 n=5+5)
DiscardLogV9Info-36 239ns ± 2% 238ns ± 0% ~ (p=0.651 n=5+5)
DiscardLogError-36 266ns ± 0% 239ns ± 2% -10.15% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 3% 121ns ± 2% +3.41% (p=0.008 n=5+5)
DiscardWithName-36 2.24ns ± 1% 3.56ns ± 0% +58.47% (p=0.008 n=5+5)
I have updated the PR with changes as discussed so far, except for adding examples.
The last four commits implement different possible solutions:
- no caching, everything in Logger except for slice, which has to be a pointer
- no caching, new fields in separate struct
- caching in that struct
- caching with fields back in Logger
The baseline is the solution with no changes to logr.
Obviously, caching favors benchmarks where the same or related Logger instances are used multiple times. The last two differ a bit here because with the separate struct, more Loggers share the same cached sink (parent and siblings). This difference is currently not covered by a benchmark.
Some benchmarks are very fast, so any slowdown shows up with a huge percentage. I am not sure how relevant that is in practice because they are still fast. It's also often the Discard* tests - those are irrelevant for Kubernetes production components because we always return a logger, but may of course matter in other projects.
Let's look at a comparison between the baseline and different options:
- no caching, inline
name old time/op new time/op delta
DiscardLogInfoOneArg-36 96.1ns ± 2% 111.3ns ± 2% +15.78% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 241ns ± 0% 252ns ± 0% +4.96% (p=0.008 n=5+5)
DiscardLogInfoWithValues-36 243ns ± 3% 258ns ± 1% +6.00% (p=0.008 n=5+5)
DiscardLogV0Info-36 243ns ± 2% 258ns ± 1% +6.10% (p=0.008 n=5+5)
DiscardLogV9Info-36 240ns ± 2% 263ns ± 1% +9.75% (p=0.008 n=5+5)
DiscardLogError-36 270ns ± 1% 255ns ± 2% -5.68% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 2% 140ns ± 1% +19.59% (p=0.008 n=5+5)
DiscardWithName-36 2.28ns ± 0% 11.01ns ± 0% +382.81% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.10µs ± 2% 2.15µs ± 1% +2.31% (p=0.032 n=5+5)
FuncrJSONLogInfoOneArg-36 2.38µs ± 1% 2.42µs ± 2% ~ (p=0.056 n=5+5)
FuncrLogInfoSeveralArgs-36 4.51µs ± 5% 4.55µs ± 1% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.81µs ± 5% 4.84µs ± 3% ~ (p=0.841 n=5+5)
FuncrLogInfoWithValues-36 4.58µs ± 2% 4.61µs ± 4% ~ (p=0.310 n=5+5)
FuncrJSONLogInfoWithValues-36 4.86µs ± 3% 4.94µs ± 2% ~ (p=0.310 n=5+5)
FuncrLogV0Info-36 4.60µs ± 2% 4.55µs ± 3% ~ (p=0.421 n=5+5)
FuncrJSONLogV0Info-36 4.88µs ± 2% 4.82µs ± 1% ~ (p=0.310 n=5+5)
FuncrLogV9Info-36 249ns ± 1% 279ns ± 2% +12.35% (p=0.008 n=5+5)
FuncrJSONLogV9Info-36 250ns ± 1% 280ns ± 1% +11.93% (p=0.008 n=5+5)
FuncrLogError-36 4.86µs ± 3% 4.80µs ± 2% ~ (p=0.421 n=5+5)
FuncrJSONLogError-36 5.01µs ± 4% 5.10µs ± 1% ~ (p=0.151 n=5+5)
FuncrWithValues-36 1.27µs ± 7% 1.29µs ± 5% ~ (p=0.690 n=5+5)
FuncrWithName-36 177ns ± 4% 199ns ± 1% +12.28% (p=0.008 n=5+5)
FuncrWithCallDepth-36 168ns ± 1% 174ns ± 1% +3.84% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.64µs ± 2% 2.64µs ± 1% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.64µs ± 2% 2.62µs ± 2% ~ (p=0.508 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.66µs ± 1% 2.65µs ± 2% ~ (p=0.421 n=5+5)
FromContext/no-logger-36 2.40ns ± 0% 12.94ns ± 0% +438.97% (p=0.008 n=5+5)
FromContext/with-logger-36 5.79ns ± 1% 18.95ns ± 0% +227.24% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 2.90ns ± 2% 10.07ns ± 0% +246.63% (p=0.008 n=5+5)
FromContextOrDiscard/with-logger-36 5.52ns ± 1% 16.50ns ± 2% +198.61% (p=0.008 n=5+5)
NewContext1Percent/simple-36 191µs ± 4% 48µs ± 1% -75.12% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 228µs ± 2% 48µs ± 2% -78.96% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 192µs ± 2% 50µs ± 2% -74.09% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 193µs ± 5% 48µs ± 1% -74.96% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 194µs ± 1% 50µs ± 1% -74.44% (p=0.016 n=4+5)
NewContext1Percent/WithNameAndValuesBefore-36 228µs ± 3% 49µs ± 2% -78.71% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 208µs ± 3% 67µs ± 2% -67.76% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 247µs ± 4% 67µs ± 2% -72.96% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 347µs ± 1% 162µs ± 3% -53.50% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 230µs ± 3% 89µs ± 1% -61.08% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 374µs ± 2% 183µs ± 3% -51.04% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 273µs ± 3% 89µs ± 3% -67.46% (p=0.008 n=5+5)
NewContext100Percent/simple-36 538µs ± 3% 523µs ± 3% ~ (p=0.056 n=5+5)
NewContext100Percent/WithValuesBefore-36 608µs ± 2% 588µs ± 3% ~ (p=0.056 n=5+5)
NewContext100Percent/WithValuesAfter-36 712µs ± 4% 692µs ± 3% ~ (p=0.151 n=5+5)
NewContext100Percent/WithName-36 590µs ± 2% 572µs ± 3% -3.07% (p=0.032 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 754µs ± 2% 707µs ± 2% -6.18% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 636µs ± 1% 621µs ± 2% -2.34% (p=0.008 n=5+5)
NewContextMany/simple-36 3.63ms ± 2% 4.67ms ± 3% +28.62% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 3.72ms ± 1% 5.35ms ± 1% +43.75% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 3.85ms ± 0% 5.48ms ± 1% +42.49% (p=0.008 n=5+5)
NewContextMany/WithName-36 3.88ms ± 1% 5.02ms ± 2% +29.36% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 4.15ms ± 1% 5.47ms ± 4% +31.83% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 3.97ms ± 2% 5.47ms ± 2% +37.81% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FromContext/no-logger-36 0.00B 0.00B ~ (all equal)
FromContext/with-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/no-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00B 0.00B ~ (all equal)
NewContext1Percent/simple-36 50.6kB ± 0% 19.1kB ± 0% -62.19% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 57.3kB ± 0% 19.2kB ± 0% -66.45% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 50.9kB ± 0% 19.4kB ± 0% -61.92% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 50.8kB ± 0% 19.3kB ± 0% -62.01% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 51.1kB ± 0% 19.5kB ± 0% -61.76% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 57.5kB ± 0% 19.4kB ± 0% -66.30% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 58.9kB ± 0% 27.2kB ± 0% -53.85% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 65.6kB ± 0% 27.2kB ± 0% -58.54% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 86.7kB ± 0% 43.2kB ± 0% -50.15% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 68.5kB ± 0% 36.8kB ± 0% -46.30% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 96.3kB ± 0% 52.8kB ± 0% -45.15% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 75.2kB ± 0% 36.8kB ± 0% -51.06% (p=0.008 n=5+5)
NewContext100Percent/simple-36 179kB ± 0% 172kB ± 0% -4.02% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 188kB ± 0% 181kB ± 0% -3.83% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 209kB ± 0% 197kB ± 0% -5.75% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 194kB ± 0% 186kB ± 0% -3.72% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 223kB ± 0% 210kB ± 0% -5.73% (p=0.029 n=4+4)
NewContext100Percent/WithNameAndValuesBefore-36 202kB ± 0% 194kB ± 0% -3.57% (p=0.029 n=4+4)
NewContextMany/simple-36 1.35MB ± 0% 1.56MB ± 0% +15.45% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 1.37MB ± 0% 1.65MB ± 0% +19.91% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 1.40MB ± 0% 1.66MB ± 0% +19.27% (p=0.008 n=5+5)
NewContextMany/WithName-36 1.41MB ± 0% 1.62MB ± 0% +14.82% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 1.45MB ± 0% 1.71MB ± 0% +17.95% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 1.43MB ± 0% 1.70MB ± 0% +18.61% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FromContext/no-logger-36 0.00 0.00 ~ (all equal)
FromContext/with-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/no-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00 0.00 ~ (all equal)
NewContext1Percent/simple-36 1.11k ± 0% 0.32k ± 0% -71.47% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.67% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 1.12k ± 0% 0.32k ± 0% -71.02% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 1.11k ± 0% 0.32k ± 0% -71.34% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.89% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.55% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 1.20k ± 0% 0.40k ± 0% -66.67% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 1.40k ± 0% 0.40k ± 0% -71.43% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 1.90k ± 0% 0.90k ± 0% -52.63% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 1.30k ± 0% 0.50k ± 0% -61.54% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 2.00k ± 0% 1.00k ± 0% -50.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 1.50k ± 0% 0.50k ± 0% -66.67% (p=0.008 n=5+5)
NewContext100Percent/simple-36 2.20k ± 0% 2.00k ± 0% -9.09% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 2.40k ± 0% 2.20k ± 0% -8.33% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 2.90k ± 0% 2.70k ± 0% -6.90% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 2.40k ± 0% 2.20k ± 0% -8.33% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 3.10k ± 0% 2.90k ± 0% -6.45% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 2.60k ± 0% 2.40k ± 0% -7.69% (p=0.008 n=5+5)
NewContextMany/simple-36 12.1k ± 0% 17.3k ± 0% +42.98% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 12.3k ± 0% 19.3k ± 0% +56.91% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 12.8k ± 0% 19.8k ± 0% +54.69% (p=0.008 n=5+5)
NewContextMany/WithName-36 13.2k ± 0% 18.4k ± 0% +39.39% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 13.9k ± 0% 20.9k ± 0% +50.36% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 13.4k ± 0% 20.4k ± 0% +52.24% (p=0.008 n=5+5)
- no cache, struct:
Here FromContext/with-logger and FromContextOrDiscard/with-logger stand out because they need to allocate. This could be optimized away if the returned logger is the Discard logger, but on the other hand that is the overhead that we'll see for other loggers.
name old time/op new time/op delta
DiscardLogInfoOneArg-36 96.1ns ± 2% 99.8ns ± 3% +3.81% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 241ns ± 0% 240ns ± 1% ~ (p=0.873 n=5+5)
DiscardLogInfoWithValues-36 243ns ± 3% 242ns ± 1% ~ (p=0.841 n=5+5)
DiscardLogV0Info-36 243ns ± 2% 241ns ± 1% ~ (p=0.222 n=5+5)
DiscardLogV9Info-36 240ns ± 2% 242ns ± 1% ~ (p=0.151 n=5+5)
DiscardLogError-36 270ns ± 1% 243ns ± 1% -10.15% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 2% 122ns ± 1% +4.06% (p=0.008 n=5+5)
DiscardWithName-36 2.28ns ± 0% 3.83ns ± 0% +68.00% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.10µs ± 2% 2.14µs ± 1% +1.81% (p=0.032 n=5+5)
FuncrJSONLogInfoOneArg-36 2.38µs ± 1% 2.41µs ± 0% +1.48% (p=0.008 n=5+5)
FuncrLogInfoSeveralArgs-36 4.51µs ± 5% 4.51µs ± 6% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.81µs ± 5% 4.86µs ± 2% ~ (p=0.690 n=5+5)
FuncrLogInfoWithValues-36 4.58µs ± 2% 4.63µs ± 4% ~ (p=0.151 n=5+5)
FuncrJSONLogInfoWithValues-36 4.86µs ± 3% 4.88µs ± 2% ~ (p=0.548 n=5+5)
FuncrLogV0Info-36 4.60µs ± 2% 4.54µs ± 2% ~ (p=0.310 n=5+5)
FuncrJSONLogV0Info-36 4.88µs ± 2% 4.84µs ± 2% ~ (p=0.548 n=5+5)
FuncrLogV9Info-36 249ns ± 1% 250ns ± 1% ~ (p=0.310 n=5+5)
FuncrJSONLogV9Info-36 250ns ± 1% 249ns ± 1% ~ (p=0.690 n=5+5)
FuncrLogError-36 4.86µs ± 3% 4.82µs ± 4% ~ (p=0.548 n=5+5)
FuncrJSONLogError-36 5.01µs ± 4% 5.05µs ± 1% ~ (p=0.421 n=5+5)
FuncrWithValues-36 1.27µs ± 7% 1.23µs ± 6% ~ (p=0.095 n=5+5)
FuncrWithName-36 177ns ± 4% 181ns ± 1% ~ (p=0.254 n=5+5)
FuncrWithCallDepth-36 168ns ± 1% 166ns ± 2% ~ (p=0.508 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.64µs ± 2% 2.57µs ± 1% -2.49% (p=0.032 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.64µs ± 2% 2.58µs ± 1% ~ (p=0.056 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.66µs ± 1% 2.61µs ± 3% -2.04% (p=0.016 n=5+5)
FromContext/no-logger-36 2.40ns ± 0% 4.09ns ± 0% +70.20% (p=0.008 n=5+5)
FromContext/with-logger-36 5.79ns ± 1% 127.20ns ± 2% +2096.36% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 2.90ns ± 2% 3.62ns ± 1% +24.70% (p=0.008 n=5+5)
FromContextOrDiscard/with-logger-36 5.52ns ± 1% 126.74ns ± 2% +2194.27% (p=0.008 n=5+5)
NewContext1Percent/simple-36 191µs ± 4% 47µs ± 1% -75.21% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 228µs ± 2% 48µs ± 3% -78.97% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 192µs ± 2% 49µs ± 1% -74.45% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 193µs ± 5% 48µs ± 1% -75.19% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 194µs ± 1% 50µs ± 2% -74.13% (p=0.016 n=4+5)
NewContext1Percent/WithNameAndValuesBefore-36 228µs ± 3% 49µs ± 1% -78.55% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 208µs ± 3% 74µs ± 2% -64.55% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 247µs ± 4% 74µs ± 1% -70.10% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 347µs ± 1% 167µs ± 6% -51.91% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 230µs ± 3% 93µs ± 1% -59.33% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 374µs ± 2% 186µs ± 2% -50.28% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 273µs ± 3% 93µs ± 1% -65.97% (p=0.008 n=5+5)
NewContext100Percent/simple-36 538µs ± 3% 523µs ± 1% ~ (p=0.056 n=5+5)
NewContext100Percent/WithValuesBefore-36 608µs ± 2% 586µs ± 4% -3.55% (p=0.032 n=5+5)
NewContext100Percent/WithValuesAfter-36 712µs ± 4% 688µs ± 2% -3.41% (p=0.032 n=5+5)
NewContext100Percent/WithName-36 590µs ± 2% 578µs ± 3% ~ (p=0.222 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 754µs ± 2% 709µs ± 2% -5.96% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 636µs ± 1% 614µs ± 2% -3.39% (p=0.008 n=5+5)
NewContextMany/simple-36 3.63ms ± 2% 4.64ms ± 3% +27.77% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 3.72ms ± 1% 5.17ms ± 2% +38.75% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 3.85ms ± 0% 5.35ms ± 2% +39.13% (p=0.008 n=5+5)
NewContextMany/WithName-36 3.88ms ± 1% 4.85ms ± 1% +25.14% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 4.15ms ± 1% 5.46ms ± 4% +31.47% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 3.97ms ± 2% 5.28ms ± 2% +32.99% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FromContext/no-logger-36 0.00B 0.00B ~ (all equal)
FromContext/with-logger-36 0.00B 48.00B ± 0% +Inf% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00B 48.00B ± 0% +Inf% (p=0.008 n=5+5)
NewContext1Percent/simple-36 50.6kB ± 0% 19.2kB ± 0% -62.10% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 57.3kB ± 0% 19.3kB ± 0% -66.36% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 50.9kB ± 0% 19.4kB ± 0% -61.83% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 50.8kB ± 0% 19.3kB ± 0% -61.92% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 51.1kB ± 0% 19.6kB ± 0% -61.67% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 57.5kB ± 0% 19.4kB ± 0% -66.21% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 58.9kB ± 0% 32.0kB ± 0% -45.70% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 65.6kB ± 0% 32.0kB ± 0% -51.22% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 86.7kB ± 0% 48.0kB ± 0% -44.62% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 68.5kB ± 0% 41.6kB ± 0% -39.30% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 96.3kB ± 0% 57.6kB ± 0% -40.17% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 75.2kB ± 0% 41.6kB ± 0% -44.68% (p=0.008 n=5+5)
NewContext100Percent/simple-36 179kB ± 0% 177kB ± 0% -1.34% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 188kB ± 0% 186kB ± 0% -1.28% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 209kB ± 0% 202kB ± 0% -3.45% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 194kB ± 0% 191kB ± 0% -1.24% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 223kB ± 0% 215kB ± 0% ~ (p=0.079 n=4+5)
NewContext100Percent/WithNameAndValuesBefore-36 202kB ± 0% 199kB ± 0% ~ (p=0.079 n=4+5)
NewContextMany/simple-36 1.35MB ± 0% 1.56MB ± 0% +15.81% (p=0.016 n=5+4)
NewContextMany/WithValuesBefore-36 1.37MB ± 0% 1.65MB ± 0% +20.26% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 1.40MB ± 0% 1.67MB ± 0% +19.61% (p=0.008 n=5+5)
NewContextMany/WithName-36 1.41MB ± 0% 1.62MB ± 0% +15.16% (p=0.016 n=5+4)
NewContextMany/WithNameAndValuesAfter-36 1.45MB ± 0% 1.72MB ± 0% +18.28% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 1.43MB ± 0% 1.70MB ± 0% +18.95% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FromContext/no-logger-36 0.00 0.00 ~ (all equal)
FromContext/with-logger-36 0.00 1.00 ± 0% +Inf% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00 1.00 ± 0% +Inf% (p=0.008 n=5+5)
NewContext1Percent/simple-36 1.11k ± 0% 0.32k ± 0% -71.38% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.59% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.93% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 1.11k ± 0% 0.32k ± 0% -71.25% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.80% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.48% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 1.20k ± 0% 0.50k ± 0% -58.33% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 1.40k ± 0% 0.50k ± 0% -64.29% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 1.90k ± 0% 1.00k ± 0% -47.37% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 1.30k ± 0% 0.60k ± 0% -53.85% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 2.00k ± 0% 1.10k ± 0% -45.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 1.50k ± 0% 0.60k ± 0% -60.00% (p=0.008 n=5+5)
NewContext100Percent/simple-36 2.20k ± 0% 2.10k ± 0% -4.55% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 2.40k ± 0% 2.30k ± 0% -4.17% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 2.90k ± 0% 2.80k ± 0% -3.45% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 2.40k ± 0% 2.30k ± 0% -4.17% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 3.10k ± 0% 3.00k ± 0% -3.23% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 2.60k ± 0% 2.50k ± 0% -3.85% (p=0.008 n=5+5)
NewContextMany/simple-36 12.1k ± 0% 17.4k ± 0% +43.80% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 12.3k ± 0% 19.4k ± 0% +57.72% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 12.8k ± 0% 19.9k ± 0% +55.47% (p=0.008 n=5+5)
NewContextMany/WithName-36 13.2k ± 0% 18.5k ± 0% +40.15% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 13.9k ± 0% 21.0k ± 0% +51.08% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 13.4k ± 0% 20.5k ± 0% +52.99% (p=0.008 n=5+5)
It's faster in some benchmarks and slower in others.
- cache, with struct
Here we still pay the price for the extra allocation, but the cache seems to help.
name old time/op new time/op delta
DiscardLogInfoOneArg-36 96.1ns ± 2% 99.9ns ± 3% +3.90% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 241ns ± 0% 243ns ± 1% +1.13% (p=0.016 n=5+5)
DiscardLogInfoWithValues-36 243ns ± 3% 246ns ± 1% ~ (p=0.254 n=5+5)
DiscardLogV0Info-36 243ns ± 2% 249ns ± 2% +2.53% (p=0.032 n=5+5)
DiscardLogV9Info-36 240ns ± 2% 245ns ± 2% +2.29% (p=0.032 n=5+5)
DiscardLogError-36 270ns ± 1% 244ns ± 1% -9.73% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 2% 121ns ± 2% +2.93% (p=0.032 n=5+5)
DiscardWithName-36 2.28ns ± 0% 3.85ns ± 0% +68.74% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.10µs ± 2% 2.15µs ± 1% +2.53% (p=0.008 n=5+5)
FuncrJSONLogInfoOneArg-36 2.38µs ± 1% 2.42µs ± 1% +1.69% (p=0.032 n=5+5)
FuncrLogInfoSeveralArgs-36 4.51µs ± 5% 4.60µs ± 4% ~ (p=0.222 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.81µs ± 5% 4.69µs ± 3% ~ (p=0.095 n=5+5)
FuncrLogInfoWithValues-36 4.58µs ± 2% 4.62µs ± 2% ~ (p=0.246 n=5+5)
FuncrJSONLogInfoWithValues-36 4.86µs ± 3% 4.87µs ± 4% ~ (p=1.000 n=5+5)
FuncrLogV0Info-36 4.60µs ± 2% 4.63µs ± 2% ~ (p=0.548 n=5+5)
FuncrJSONLogV0Info-36 4.88µs ± 2% 4.78µs ± 1% ~ (p=0.095 n=5+5)
FuncrLogV9Info-36 249ns ± 1% 250ns ± 1% ~ (p=0.310 n=5+5)
FuncrJSONLogV9Info-36 250ns ± 1% 249ns ± 1% ~ (p=1.000 n=5+5)
FuncrLogError-36 4.86µs ± 3% 4.88µs ± 1% ~ (p=1.000 n=5+5)
FuncrJSONLogError-36 5.01µs ± 4% 5.08µs ± 3% ~ (p=0.310 n=5+5)
FuncrWithValues-36 1.27µs ± 7% 1.27µs ± 3% ~ (p=0.841 n=5+5)
FuncrWithName-36 177ns ± 4% 180ns ± 2% ~ (p=0.421 n=5+5)
FuncrWithCallDepth-36 168ns ± 1% 171ns ± 2% +2.14% (p=0.048 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.64µs ± 2% 2.60µs ± 2% ~ (p=0.151 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.64µs ± 2% 2.61µs ± 1% ~ (p=0.071 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.66µs ± 1% 2.62µs ± 2% -1.74% (p=0.008 n=5+5)
FromContext/no-logger-36 2.40ns ± 0% 4.08ns ± 0% +69.78% (p=0.008 n=5+5)
FromContext/with-logger-36 5.79ns ± 1% 137.74ns ± 2% +2278.35% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 2.90ns ± 2% 3.60ns ± 0% +24.04% (p=0.008 n=5+5)
FromContextOrDiscard/with-logger-36 5.52ns ± 1% 134.88ns ± 1% +2341.62% (p=0.008 n=5+5)
NewContext1Percent/simple-36 191µs ± 4% 47µs ± 3% -75.48% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 228µs ± 2% 48µs ± 1% -79.07% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 192µs ± 2% 50µs ± 1% -74.03% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 193µs ± 5% 48µs ± 1% -74.89% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 194µs ± 1% 50µs ± 2% -74.39% (p=0.016 n=4+5)
NewContext1Percent/WithNameAndValuesBefore-36 228µs ± 3% 49µs ± 0% -78.71% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 208µs ± 3% 75µs ± 1% -63.92% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 247µs ± 4% 74µs ± 0% -69.86% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 347µs ± 1% 183µs ± 2% -47.37% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 230µs ± 3% 107µs ± 1% -53.49% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 374µs ± 2% 217µs ± 1% -41.97% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 273µs ± 3% 107µs ± 1% -60.74% (p=0.008 n=5+5)
NewContext100Percent/simple-36 538µs ± 3% 535µs ± 2% ~ (p=0.690 n=5+5)
NewContext100Percent/WithValuesBefore-36 608µs ± 2% 601µs ± 3% ~ (p=0.548 n=5+5)
NewContext100Percent/WithValuesAfter-36 712µs ± 4% 709µs ± 1% ~ (p=1.000 n=5+5)
NewContext100Percent/WithName-36 590µs ± 2% 590µs ± 3% ~ (p=1.000 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 754µs ± 2% 743µs ± 1% ~ (p=0.151 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 636µs ± 1% 637µs ± 1% ~ (p=0.841 n=5+5)
NewContextMany/simple-36 3.63ms ± 2% 3.63ms ± 1% ~ (p=0.690 n=5+5)
NewContextMany/WithValuesBefore-36 3.72ms ± 1% 3.72ms ± 2% ~ (p=1.000 n=5+5)
NewContextMany/WithValuesAfter-36 3.85ms ± 0% 3.87ms ± 2% ~ (p=0.548 n=5+5)
NewContextMany/WithName-36 3.88ms ± 1% 3.90ms ± 1% ~ (p=0.151 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 4.15ms ± 1% 4.06ms ± 3% ~ (p=0.095 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 3.97ms ± 2% 3.98ms ± 1% ~ (p=0.310 n=5+5)
name old alloc/op new alloc/op delta
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FromContext/no-logger-36 0.00B 0.00B ~ (all equal)
FromContext/with-logger-36 0.00B 64.00B ± 0% +Inf% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00B 64.00B ± 0% +Inf% (p=0.008 n=5+5)
NewContext1Percent/simple-36 50.6kB ± 0% 19.2kB ± 0% -62.06% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 57.3kB ± 0% 19.3kB ± 0% -66.34% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 50.9kB ± 0% 19.5kB ± 0% -61.67% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 50.8kB ± 0% 19.4kB ± 0% -61.76% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 51.1kB ± 0% 19.7kB ± 0% -61.39% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 57.5kB ± 0% 19.5kB ± 0% -66.07% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 58.9kB ± 0% 33.6kB ± 0% -42.99% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 65.6kB ± 0% 33.6kB ± 0% -48.78% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 86.7kB ± 0% 56.0kB ± 0% -35.38% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 68.5kB ± 0% 49.6kB ± 0% -27.63% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 96.3kB ± 0% 72.0kB ± 0% -25.21% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 75.2kB ± 0% 49.6kB ± 0% -34.04% (p=0.008 n=5+5)
NewContext100Percent/simple-36 179kB ± 0% 178kB ± 0% -0.45% (p=0.000 n=5+4)
NewContext100Percent/WithValuesBefore-36 188kB ± 0% 187kB ± 0% -0.43% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 209kB ± 0% 210kB ± 0% +0.38% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 194kB ± 0% 199kB ± 0% +2.89% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 223kB ± 0% 230kB ± 0% +2.87% (p=0.029 n=4+4)
NewContext100Percent/WithNameAndValuesBefore-36 202kB ± 0% 207kB ± 0% +2.78% (p=0.016 n=4+5)
NewContextMany/simple-36 1.35MB ± 0% 1.35MB ± 0% -0.06% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 1.37MB ± 0% 1.37MB ± 0% -0.06% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 1.40MB ± 0% 1.40MB ± 0% +0.06% (p=0.008 n=5+5)
NewContextMany/WithName-36 1.41MB ± 0% 1.41MB ± 0% +0.40% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 1.45MB ± 0% 1.46MB ± 0% +0.44% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 1.43MB ± 0% 1.44MB ± 0% +0.39% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FromContext/no-logger-36 0.00 0.00 ~ (all equal)
FromContext/with-logger-36 0.00 1.00 ± 0% +Inf% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00 1.00 ± 0% +Inf% (p=0.008 n=5+5)
NewContext1Percent/simple-36 1.11k ± 0% 0.32k ± 0% -71.38% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.59% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.84% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 1.11k ± 0% 0.32k ± 0% -71.16% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.62% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.40% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 1.20k ± 0% 0.50k ± 0% -58.33% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 1.40k ± 0% 0.50k ± 0% -64.29% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 1.90k ± 0% 1.10k ± 0% -42.11% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 1.30k ± 0% 0.70k ± 0% -46.15% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 2.00k ± 0% 1.30k ± 0% -35.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 1.50k ± 0% 0.70k ± 0% -53.33% (p=0.008 n=5+5)
NewContext100Percent/simple-36 2.20k ± 0% 2.10k ± 0% -4.55% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 2.40k ± 0% 2.30k ± 0% -4.17% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 2.90k ± 0% 2.90k ± 0% ~ (all equal)
NewContext100Percent/WithName-36 2.40k ± 0% 2.40k ± 0% ~ (all equal)
NewContext100Percent/WithNameAndValuesAfter-36 3.10k ± 0% 3.20k ± 0% +3.23% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 2.60k ± 0% 2.60k ± 0% ~ (all equal)
NewContextMany/simple-36 12.1k ± 0% 12.0k ± 0% -0.83% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 12.3k ± 0% 12.2k ± 0% -0.81% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 12.8k ± 0% 12.8k ± 0% ~ (all equal)
NewContextMany/WithName-36 13.2k ± 0% 13.2k ± 0% ~ (all equal)
NewContextMany/WithNameAndValuesAfter-36 13.9k ± 0% 14.0k ± 0% +0.72% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 13.4k ± 0% 13.4k ± 0% ~ (all equal)
- cache, inline
This reduces allocations, but makes copying slower and reduces sharing of the cached sink.
name old time/op new time/op delta
DiscardLogInfoOneArg-36 96.1ns ± 2% 109.7ns ± 3% +14.14% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 241ns ± 0% 254ns ± 1% +5.68% (p=0.008 n=5+5)
DiscardLogInfoWithValues-36 243ns ± 3% 252ns ± 1% +3.58% (p=0.016 n=5+5)
DiscardLogV0Info-36 243ns ± 2% 256ns ± 1% +5.18% (p=0.008 n=5+5)
DiscardLogV9Info-36 240ns ± 2% 273ns ± 1% +13.79% (p=0.008 n=5+5)
DiscardLogError-36 270ns ± 1% 255ns ± 1% -5.65% (p=0.008 n=5+5)
DiscardWithValues-36 117ns ± 2% 140ns ± 5% +19.10% (p=0.008 n=5+5)
DiscardWithName-36 2.28ns ± 0% 11.91ns ± 0% +422.36% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.10µs ± 2% 2.14µs ± 3% ~ (p=0.056 n=5+5)
FuncrJSONLogInfoOneArg-36 2.38µs ± 1% 2.43µs ± 1% +2.37% (p=0.008 n=5+5)
FuncrLogInfoSeveralArgs-36 4.51µs ± 5% 4.51µs ± 5% ~ (p=1.000 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.81µs ± 5% 4.74µs ± 3% ~ (p=0.310 n=5+5)
FuncrLogInfoWithValues-36 4.58µs ± 2% 4.62µs ± 2% ~ (p=0.222 n=5+5)
FuncrJSONLogInfoWithValues-36 4.86µs ± 3% 4.86µs ± 2% ~ (p=1.000 n=5+5)
FuncrLogV0Info-36 4.60µs ± 2% 4.53µs ± 2% ~ (p=0.056 n=5+5)
FuncrJSONLogV0Info-36 4.88µs ± 2% 4.83µs ± 3% ~ (p=0.222 n=5+5)
FuncrLogV9Info-36 249ns ± 1% 284ns ± 2% +14.36% (p=0.008 n=5+5)
FuncrJSONLogV9Info-36 250ns ± 1% 283ns ± 1% +13.31% (p=0.008 n=5+5)
FuncrLogError-36 4.86µs ± 3% 4.81µs ± 2% ~ (p=0.421 n=5+5)
FuncrJSONLogError-36 5.01µs ± 4% 5.15µs ± 3% ~ (p=0.151 n=5+5)
FuncrWithValues-36 1.27µs ± 7% 1.27µs ± 3% ~ (p=0.968 n=5+5)
FuncrWithName-36 177ns ± 4% 202ns ± 3% +14.12% (p=0.008 n=5+5)
FuncrWithCallDepth-36 168ns ± 1% 181ns ± 1% +7.78% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.64µs ± 2% 2.63µs ± 2% ~ (p=0.841 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.64µs ± 2% 2.64µs ± 1% ~ (p=0.810 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.66µs ± 1% 2.68µs ± 1% ~ (p=0.151 n=5+5)
FromContext/no-logger-36 2.40ns ± 0% 14.40ns ± 1% +499.60% (p=0.008 n=5+5)
FromContext/with-logger-36 5.79ns ± 1% 20.13ns ± 0% +247.62% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 2.90ns ± 2% 11.50ns ± 0% +296.14% (p=0.008 n=5+5)
FromContextOrDiscard/with-logger-36 5.52ns ± 1% 17.99ns ± 0% +225.69% (p=0.008 n=5+5)
NewContext1Percent/simple-36 191µs ± 4% 48µs ± 3% -75.15% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 228µs ± 2% 48µs ± 1% -78.84% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 192µs ± 2% 50µs ± 1% -74.08% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 193µs ± 5% 49µs ± 1% -74.60% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 194µs ± 1% 50µs ± 2% -74.03% (p=0.016 n=4+5)
NewContext1Percent/WithNameAndValuesBefore-36 228µs ± 3% 49µs ± 1% -78.63% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 208µs ± 3% 68µs ± 2% -67.06% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 247µs ± 4% 68µs ± 1% -72.32% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 347µs ± 1% 159µs ± 3% -54.18% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 230µs ± 3% 92µs ± 0% -60.12% (p=0.016 n=5+4)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 374µs ± 2% 184µs ± 1% -50.69% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 273µs ± 3% 91µs ± 1% -66.76% (p=0.008 n=5+5)
NewContext100Percent/simple-36 538µs ± 3% 533µs ± 2% ~ (p=0.222 n=5+5)
NewContext100Percent/WithValuesBefore-36 608µs ± 2% 587µs ± 1% -3.36% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 712µs ± 4% 692µs ± 0% ~ (p=0.190 n=5+4)
NewContext100Percent/WithName-36 590µs ± 2% 573µs ± 3% -2.90% (p=0.032 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 754µs ± 2% 714µs ± 3% -5.28% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 636µs ± 1% 620µs ± 3% -2.49% (p=0.032 n=5+5)
NewContextMany/simple-36 3.63ms ± 2% 4.74ms ± 2% +30.56% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 3.72ms ± 1% 5.43ms ± 2% +45.88% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 3.85ms ± 0% 5.49ms ± 2% +42.61% (p=0.008 n=5+5)
NewContextMany/WithName-36 3.88ms ± 1% 4.98ms ± 2% +28.48% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 4.15ms ± 1% 5.48ms ± 4% +32.12% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 3.97ms ± 2% 5.55ms ± 3% +39.87% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FromContext/no-logger-36 0.00B 0.00B ~ (all equal)
FromContext/with-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/no-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00B 0.00B ~ (all equal)
NewContext1Percent/simple-36 50.6kB ± 0% 19.1kB ± 0% -62.19% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 57.3kB ± 0% 19.2kB ± 0% -66.45% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 50.9kB ± 0% 19.4kB ± 0% -61.92% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 50.8kB ± 0% 19.3kB ± 0% -62.01% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 51.1kB ± 0% 19.5kB ± 0% -61.76% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 57.5kB ± 0% 19.4kB ± 0% -66.30% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 58.9kB ± 0% 27.2kB ± 0% -53.85% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 65.6kB ± 0% 27.2kB ± 0% -58.54% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 86.7kB ± 0% 43.2kB ± 0% -50.15% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 68.5kB ± 0% 36.8kB ± 0% -46.30% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 96.3kB ± 0% 52.8kB ± 0% -45.15% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 75.2kB ± 0% 36.8kB ± 0% -51.06% (p=0.008 n=5+5)
NewContext100Percent/simple-36 179kB ± 0% 172kB ± 0% -4.02% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 188kB ± 0% 181kB ± 0% -3.83% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 209kB ± 0% 197kB ± 0% -5.75% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 194kB ± 0% 186kB ± 0% -3.72% (p=0.000 n=5+4)
NewContext100Percent/WithNameAndValuesAfter-36 223kB ± 0% 210kB ± 0% ~ (p=0.079 n=4+5)
NewContext100Percent/WithNameAndValuesBefore-36 202kB ± 0% 194kB ± 0% -3.57% (p=0.000 n=4+5)
NewContextMany/simple-36 1.35MB ± 0% 1.56MB ± 0% +15.45% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 1.37MB ± 0% 1.65MB ± 0% +19.91% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 1.40MB ± 0% 1.66MB ± 0% +19.27% (p=0.008 n=5+5)
NewContextMany/WithName-36 1.41MB ± 0% 1.62MB ± 0% +14.82% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 1.45MB ± 0% 1.71MB ± 0% +17.95% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 1.43MB ± 0% 1.70MB ± 0% +18.61% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FromContext/no-logger-36 0.00 0.00 ~ (all equal)
FromContext/with-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/no-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/with-logger-36 0.00 0.00 ~ (all equal)
NewContext1Percent/simple-36 1.11k ± 0% 0.32k ± 0% -71.47% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.67% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 1.12k ± 0% 0.32k ± 0% -71.02% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 1.11k ± 0% 0.32k ± 0% -71.34% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 1.12k ± 0% 0.33k ± 0% -70.89% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 1.31k ± 0% 0.32k ± 0% -75.55% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 1.20k ± 0% 0.40k ± 0% -66.67% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 1.40k ± 0% 0.40k ± 0% -71.43% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 1.90k ± 0% 0.90k ± 0% -52.63% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 1.30k ± 0% 0.50k ± 0% -61.54% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 2.00k ± 0% 1.00k ± 0% -50.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 1.50k ± 0% 0.50k ± 0% -66.67% (p=0.008 n=5+5)
NewContext100Percent/simple-36 2.20k ± 0% 2.00k ± 0% -9.09% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 2.40k ± 0% 2.20k ± 0% -8.33% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 2.90k ± 0% 2.70k ± 0% -6.90% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 2.40k ± 0% 2.20k ± 0% -8.33% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 3.10k ± 0% 2.90k ± 0% -6.45% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 2.60k ± 0% 2.40k ± 0% -7.69% (p=0.008 n=5+5)
NewContextMany/simple-36 12.1k ± 0% 17.3k ± 0% +42.98% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 12.3k ± 0% 19.3k ± 0% +56.91% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 12.8k ± 0% 19.8k ± 0% +54.69% (p=0.008 n=5+5)
NewContextMany/WithName-36 13.2k ± 0% 18.4k ± 0% +39.39% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 13.9k ± 0% 20.9k ± 0% +50.36% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 13.4k ± 0% 20.4k ± 0% +52.24% (p=0.008 n=5+5)
I'm leaning towards picking a solution which uses the cached sink. Let's compare the two versions (with cache, struct vs. inline):
name old time/op new time/op delta
DiscardLogInfoOneArg-36 100ns ± 3% 110ns ± 3% +9.86% (p=0.008 n=5+5)
DiscardLogInfoSeveralArgs-36 243ns ± 1% 254ns ± 1% +4.50% (p=0.008 n=5+5)
DiscardLogInfoWithValues-36 246ns ± 1% 252ns ± 1% +2.56% (p=0.008 n=5+5)
DiscardLogV0Info-36 249ns ± 2% 256ns ± 1% +2.58% (p=0.008 n=5+5)
DiscardLogV9Info-36 245ns ± 2% 273ns ± 1% +11.24% (p=0.008 n=5+5)
DiscardLogError-36 244ns ± 1% 255ns ± 1% +4.53% (p=0.008 n=5+5)
DiscardWithValues-36 121ns ± 2% 140ns ± 5% +15.71% (p=0.008 n=5+5)
DiscardWithName-36 3.85ns ± 0% 11.91ns ± 0% +209.57% (p=0.008 n=5+5)
FuncrLogInfoOneArg-36 2.15µs ± 1% 2.14µs ± 3% ~ (p=0.873 n=5+5)
FuncrJSONLogInfoOneArg-36 2.42µs ± 1% 2.43µs ± 1% ~ (p=0.167 n=5+5)
FuncrLogInfoSeveralArgs-36 4.60µs ± 4% 4.51µs ± 5% ~ (p=0.151 n=5+5)
FuncrJSONLogInfoSeveralArgs-36 4.69µs ± 3% 4.74µs ± 3% ~ (p=0.548 n=5+5)
FuncrLogInfoWithValues-36 4.62µs ± 2% 4.62µs ± 2% ~ (p=0.690 n=5+5)
FuncrJSONLogInfoWithValues-36 4.87µs ± 4% 4.86µs ± 2% ~ (p=0.690 n=5+5)
FuncrLogV0Info-36 4.63µs ± 2% 4.53µs ± 2% -2.08% (p=0.016 n=5+5)
FuncrJSONLogV0Info-36 4.78µs ± 1% 4.83µs ± 3% ~ (p=0.548 n=5+5)
FuncrLogV9Info-36 250ns ± 1% 284ns ± 2% +13.91% (p=0.008 n=5+5)
FuncrJSONLogV9Info-36 249ns ± 1% 283ns ± 1% +13.54% (p=0.008 n=5+5)
FuncrLogError-36 4.88µs ± 1% 4.81µs ± 2% ~ (p=0.056 n=5+5)
FuncrJSONLogError-36 5.08µs ± 3% 5.15µs ± 3% ~ (p=0.421 n=5+5)
FuncrWithValues-36 1.27µs ± 3% 1.27µs ± 3% ~ (p=0.897 n=5+5)
FuncrWithName-36 180ns ± 2% 202ns ± 3% +12.72% (p=0.008 n=5+5)
FuncrWithCallDepth-36 171ns ± 2% 181ns ± 1% +5.53% (p=0.008 n=5+5)
FuncrJSONLogInfoStringerValue-36 2.60µs ± 2% 2.63µs ± 2% ~ (p=0.222 n=5+5)
FuncrJSONLogInfoErrorValue-36 2.61µs ± 1% 2.64µs ± 1% ~ (p=0.079 n=5+5)
FuncrJSONLogInfoMarshalerValue-36 2.62µs ± 2% 2.68µs ± 1% +2.46% (p=0.008 n=5+5)
FromContext/no-logger-36 4.08ns ± 0% 14.40ns ± 1% +253.17% (p=0.008 n=5+5)
FromContext/with-logger-36 138ns ± 2% 20ns ± 0% -85.38% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 3.60ns ± 0% 11.50ns ± 0% +219.38% (p=0.008 n=5+5)
FromContextOrDiscard/with-logger-36 135ns ± 1% 18ns ± 0% -86.66% (p=0.008 n=5+5)
NewContext1Percent/simple-36 46.9µs ± 3% 47.5µs ± 3% ~ (p=0.310 n=5+5)
NewContext1Percent/WithValuesBefore-36 47.8µs ± 1% 48.3µs ± 1% ~ (p=0.056 n=5+5)
NewContext1Percent/WithValuesAfter-36 49.9µs ± 1% 49.8µs ± 1% ~ (p=0.690 n=5+5)
NewContext1Percent/WithName-36 48.4µs ± 1% 48.9µs ± 1% ~ (p=0.095 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 49.6µs ± 2% 50.3µs ± 2% ~ (p=0.222 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 48.6µs ± 0% 48.7µs ± 1% ~ (p=0.690 n=5+5)
NewContext100PercentDisabled/simple-36 75.0µs ± 1% 68.5µs ± 2% -8.71% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 74.5µs ± 0% 68.4µs ± 1% -8.17% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 183µs ± 2% 159µs ± 3% -12.95% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 107µs ± 1% 92µs ± 0% -14.27% (p=0.016 n=5+4)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 217µs ± 1% 184µs ± 1% -15.03% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 107µs ± 1% 91µs ± 1% -15.32% (p=0.008 n=5+5)
NewContext100Percent/simple-36 535µs ± 2% 533µs ± 2% ~ (p=0.841 n=5+5)
NewContext100Percent/WithValuesBefore-36 601µs ± 3% 587µs ± 1% ~ (p=0.056 n=5+5)
NewContext100Percent/WithValuesAfter-36 709µs ± 1% 692µs ± 0% -2.39% (p=0.016 n=5+4)
NewContext100Percent/WithName-36 590µs ± 3% 573µs ± 3% ~ (p=0.056 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 743µs ± 1% 714µs ± 3% -3.92% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 637µs ± 1% 620µs ± 3% -2.65% (p=0.032 n=5+5)
NewContextMany/simple-36 3.63ms ± 1% 4.74ms ± 2% +30.69% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 3.72ms ± 2% 5.43ms ± 2% +46.07% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 3.87ms ± 2% 5.49ms ± 2% +41.68% (p=0.008 n=5+5)
NewContextMany/WithName-36 3.90ms ± 1% 4.98ms ± 2% +27.83% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 4.06ms ± 3% 5.48ms ± 4% +34.99% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 3.98ms ± 1% 5.55ms ± 3% +39.52% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
DiscardLogInfoOneArg-36 32.0B ± 0% 32.0B ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV0Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardLogError-36 176B ± 0% 176B ± 0% ~ (all equal)
DiscardWithValues-36 64.0B ± 0% 64.0B ± 0% ~ (all equal)
DiscardWithName-36 0.00B 0.00B ~ (all equal)
FuncrLogInfoOneArg-36 1.15kB ± 0% 1.15kB ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 1.17kB ± 0% 1.17kB ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 1.45kB ± 0% 1.45kB ± 0% ~ (all equal)
FuncrLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 176B ± 0% 176B ± 0% ~ (all equal)
FuncrLogError-36 1.48kB ± 0% 1.48kB ± 0% ~ (all equal)
FuncrJSONLogError-36 1.50kB ± 0% 1.50kB ± 0% ~ (all equal)
FuncrWithValues-36 264B ± 0% 264B ± 0% ~ (all equal)
FuncrWithName-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrWithCallDepth-36 96.0B ± 0% 96.0B ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 1.20kB ± 0% 1.20kB ± 0% ~ (all equal)
FromContext/no-logger-36 0.00B 0.00B ~ (all equal)
FromContext/with-logger-36 64.0B ± 0% 0.0B -100.00% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00B 0.00B ~ (all equal)
FromContextOrDiscard/with-logger-36 64.0B ± 0% 0.0B -100.00% (p=0.008 n=5+5)
NewContext1Percent/simple-36 19.2kB ± 0% 19.1kB ± 0% -0.33% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 19.3kB ± 0% 19.2kB ± 0% -0.33% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 19.5kB ± 0% 19.4kB ± 0% -0.66% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 19.4kB ± 0% 19.3kB ± 0% -0.66% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 19.7kB ± 0% 19.5kB ± 0% -0.97% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 19.5kB ± 0% 19.4kB ± 0% -0.66% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 33.6kB ± 0% 27.2kB ± 0% -19.05% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 33.6kB ± 0% 27.2kB ± 0% -19.05% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 56.0kB ± 0% 43.2kB ± 0% -22.86% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 49.6kB ± 0% 36.8kB ± 0% -25.81% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 72.0kB ± 0% 52.8kB ± 0% -26.67% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 49.6kB ± 0% 36.8kB ± 0% -25.81% (p=0.008 n=5+5)
NewContext100Percent/simple-36 178kB ± 0% 172kB ± 0% ~ (p=0.079 n=4+5)
NewContext100Percent/WithValuesBefore-36 187kB ± 0% 181kB ± 0% -3.42% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 210kB ± 0% 197kB ± 0% -6.11% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 199kB ± 0% 186kB ± 0% -6.43% (p=0.000 n=5+4)
NewContext100Percent/WithNameAndValuesAfter-36 230kB ± 0% 210kB ± 0% ~ (p=0.079 n=4+5)
NewContext100Percent/WithNameAndValuesBefore-36 207kB ± 0% 194kB ± 0% -6.18% (p=0.008 n=5+5)
NewContextMany/simple-36 1.35MB ± 0% 1.56MB ± 0% +15.52% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 1.37MB ± 0% 1.65MB ± 0% +19.98% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 1.40MB ± 0% 1.66MB ± 0% +19.20% (p=0.008 n=5+5)
NewContextMany/WithName-36 1.41MB ± 0% 1.62MB ± 0% +14.37% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 1.46MB ± 0% 1.71MB ± 0% +17.43% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 1.44MB ± 0% 1.70MB ± 0% +18.15% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
DiscardLogInfoOneArg-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardLogInfoSeveralArgs-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogInfoWithValues-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV0Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardLogError-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
DiscardWithValues-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
DiscardWithName-36 0.00 0.00 ~ (all equal)
FuncrLogInfoOneArg-36 7.00 ± 0% 7.00 ± 0% ~ (all equal)
FuncrJSONLogInfoOneArg-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrLogInfoSeveralArgs-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoSeveralArgs-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogInfoWithValues-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogInfoWithValues-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV0Info-36 17.0 ± 0% 17.0 ± 0% ~ (all equal)
FuncrJSONLogV0Info-36 18.0 ± 0% 18.0 ± 0% ~ (all equal)
FuncrLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrJSONLogV9Info-36 2.00 ± 0% 2.00 ± 0% ~ (all equal)
FuncrLogError-36 19.0 ± 0% 19.0 ± 0% ~ (all equal)
FuncrJSONLogError-36 20.0 ± 0% 20.0 ± 0% ~ (all equal)
FuncrWithValues-36 8.00 ± 0% 8.00 ± 0% ~ (all equal)
FuncrWithName-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrWithCallDepth-36 1.00 ± 0% 1.00 ± 0% ~ (all equal)
FuncrJSONLogInfoStringerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoErrorValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FuncrJSONLogInfoMarshalerValue-36 10.0 ± 0% 10.0 ± 0% ~ (all equal)
FromContext/no-logger-36 0.00 0.00 ~ (all equal)
FromContext/with-logger-36 1.00 ± 0% 0.00 -100.00% (p=0.008 n=5+5)
FromContextOrDiscard/no-logger-36 0.00 0.00 ~ (all equal)
FromContextOrDiscard/with-logger-36 1.00 ± 0% 0.00 -100.00% (p=0.008 n=5+5)
NewContext1Percent/simple-36 318 ± 0% 317 ± 0% -0.31% (p=0.008 n=5+5)
NewContext1Percent/WithValuesBefore-36 320 ± 0% 319 ± 0% -0.31% (p=0.008 n=5+5)
NewContext1Percent/WithValuesAfter-36 326 ± 0% 324 ± 0% -0.61% (p=0.008 n=5+5)
NewContext1Percent/WithName-36 321 ± 0% 319 ± 0% -0.62% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesAfter-36 329 ± 0% 326 ± 0% -0.91% (p=0.008 n=5+5)
NewContext1Percent/WithNameAndValuesBefore-36 323 ± 0% 321 ± 0% -0.62% (p=0.008 n=5+5)
NewContext100PercentDisabled/simple-36 500 ± 0% 400 ± 0% -20.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesBefore-36 500 ± 0% 400 ± 0% -20.00% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithValuesAfter-36 1.10k ± 0% 0.90k ± 0% -18.18% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithName-36 700 ± 0% 500 ± 0% -28.57% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesAfter-36 1.30k ± 0% 1.00k ± 0% -23.08% (p=0.008 n=5+5)
NewContext100PercentDisabled/WithNameAndValuesBefore-36 700 ± 0% 500 ± 0% -28.57% (p=0.008 n=5+5)
NewContext100Percent/simple-36 2.10k ± 0% 2.00k ± 0% -4.76% (p=0.008 n=5+5)
NewContext100Percent/WithValuesBefore-36 2.30k ± 0% 2.20k ± 0% -4.35% (p=0.008 n=5+5)
NewContext100Percent/WithValuesAfter-36 2.90k ± 0% 2.70k ± 0% -6.90% (p=0.008 n=5+5)
NewContext100Percent/WithName-36 2.40k ± 0% 2.20k ± 0% -8.33% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesAfter-36 3.20k ± 0% 2.90k ± 0% -9.38% (p=0.008 n=5+5)
NewContext100Percent/WithNameAndValuesBefore-36 2.60k ± 0% 2.40k ± 0% -7.69% (p=0.008 n=5+5)
NewContextMany/simple-36 12.0k ± 0% 17.3k ± 0% +44.17% (p=0.008 n=5+5)
NewContextMany/WithValuesBefore-36 12.2k ± 0% 19.3k ± 0% +58.20% (p=0.008 n=5+5)
NewContextMany/WithValuesAfter-36 12.8k ± 0% 19.8k ± 0% +54.69% (p=0.008 n=5+5)
NewContextMany/WithName-36 13.2k ± 0% 18.4k ± 0% +39.39% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesAfter-36 14.0k ± 0% 20.9k ± 0% +49.29% (p=0.008 n=5+5)
NewContextMany/WithNameAndValuesBefore-36 13.4k ± 0% 20.4k ± 0% +52.24% (p=0.008 n=5+5)
Not doing the additional allocation in FromContext favors the scenario where a logger gets retrieved without then actually logging anything.
I may be good to first get one component instrumented (like the apiserver) and do some real-world benchmarks with that component before deciding.
I'm trying to figure the best way to visualize these for a few of the most critical test cases. Ran out of time this afternoon
Should we regroup on this topic, or should we start to make noises about using slog instead?
When is slog going to be stable enough to use it as logging API in Kubernetes?
I agree that the end goal should be to use slog in Kubernetes libs, with traditional output formats (text, JSON) provided as slog backends. But for that we probably need an update of the contextual logging KEP. I've not investigated what changes would be necessary.
I don't know the answer and I have not investigated either. I'm just feeling less inclined to do major logr work now that slog is on the horizon, unless it makes it easier to adopt slog.
On Tue, Dec 27, 2022 at 10:55 AM Patrick Ohly @.***> wrote:
When is slog going to be stable enough to use it as logging API in Kubernetes?
I agree that the end goal should be to use slog in Kubernetes libs, with traditional output formats (text, JSON) provided as slog backends. But for that we probably need an update of the contextual logging KEP. I've not investigated what changes would be necessary.
— Reply to this email directly, view it on GitHub https://github.com/go-logr/logr/pull/158#issuecomment-1366106275, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABKWAVHK3WAG6QGSYVD5YSTWPM3Q7ANCNFSM6AAAAAASEOZEG4 . You are receiving this because you were assigned.Message ID: @.***>
That makes sense. We need to understand a possible timeline before we can decide whether adding new features is still needed.
Let's not pursue this further.