trace: don't allocate all events upfront
SetMaxEvent allocates storage for all events, which is very expensive
if we want to set a high value; even with small values, the
unnecessary allocation of the initial slice is measurable.
We improve the performance by having a few events preallocated as part
of the trace, and appending as necessary. We also co-locate the flags
in event which makes it smaller (by a word).
We also add a set of benchmarks; before and after amortized cost
per-event is shown:
name old time/op new time/op delta
Trace/0-2-32 1.19µs ± 1% 0.96µs ± 0% -18.94% (p=0.008 n=5+5)
Trace/0-10-32 579ns ± 0% 635ns ± 1% +9.82% (p=0.008 n=5+5)
Trace/0-100-32 463ns ± 1% 466ns ± 1% ~ (p=0.190 n=5+5)
Trace/0-1000-32 451ns ± 1% 451ns ± 0% ~ (p=0.984 n=5+5)
Trace/0-10000-32 451ns ± 2% 449ns ± 1% ~ (p=0.492 n=5+5)
Trace/10-2-32 1.41µs ± 1% 0.96µs ± 1% -31.74% (p=0.008 n=5+5)
Trace/10-10-32 623ns ± 1% 634ns ± 1% +1.73% (p=0.008 n=5+5)
Trace/10-100-32 469ns ± 1% 466ns ± 1% ~ (p=0.357 n=5+5)
Trace/10-1000-32 452ns ± 1% 453ns ± 2% ~ (p=0.913 n=5+5)
Trace/10-10000-32 451ns ± 1% 449ns ± 1% ~ (p=0.175 n=5+5)
Trace/100-2-32 2.78µs ± 2% 0.97µs ± 1% -65.28% (p=0.008 n=5+5)
Trace/100-10-32 912ns ± 1% 637ns ± 1% -30.23% (p=0.008 n=5+5)
Trace/100-100-32 479ns ± 1% 541ns ± 0% +12.77% (p=0.008 n=5+5)
Trace/100-1000-32 510ns ± 0% 541ns ± 1% +6.08% (p=0.008 n=5+5)
Trace/100-10000-32 514ns ± 1% 540ns ± 0% +5.14% (p=0.008 n=5+5)
Trace/1000-2-32 17.2µs ± 1% 1.0µs ± 1% -94.39% (p=0.008 n=5+5)
Trace/1000-10-32 3.90µs ± 1% 0.64µs ± 0% -83.68% (p=0.008 n=5+5)
Trace/1000-100-32 814ns ± 1% 542ns ± 0% -33.46% (p=0.008 n=5+5)
Trace/1000-1000-32 503ns ± 1% 581ns ± 0% +15.56% (p=0.008 n=5+5)
Trace/1000-10000-32 1.28µs ± 2% 1.03µs ± 1% -19.68% (p=0.008 n=5+5)
Change-Id: If7c68bb1809fb92fa5d06cb6640be5e09e1f131f
Reviewed-on: https://go-review.googlesource.com/30374
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
2 files changed
