1
0
mirror of https://github.com/golang/go synced 2024-11-18 14:14:46 -07:00
go/internal/telemetry/bench_test.go

198 lines
4.1 KiB
Go
Raw Normal View History

package telemetry_test
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
import (
"context"
stdlog "log"
"strings"
"testing"
"golang.org/x/tools/internal/telemetry"
"golang.org/x/tools/internal/telemetry/export"
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
tellog "golang.org/x/tools/internal/telemetry/log"
"golang.org/x/tools/internal/telemetry/tag"
teltrace "golang.org/x/tools/internal/telemetry/trace"
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
)
func init() {
stdlog.SetOutput(new(noopWriter))
}
type noopWriter int
func (nw *noopWriter) Write(b []byte) (int, error) {
return len(b), nil
}
func A(ctx context.Context, a int) int {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
if a > 0 {
_ = 10 * 12
}
return B(ctx, "Called from A")
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
}
func B(ctx context.Context, b string) int {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b = strings.ToUpper(b)
if len(b) > 1024 {
b = strings.ToLower(b)
}
return len(b)
}
func A_log(ctx context.Context, a int) int {
if a > 0 {
tellog.Print(ctx, "a > 0", tag.Of("a", a))
_ = 10 * 12
}
tellog.Print(ctx, "calling b")
return B_log(ctx, "Called from A")
}
func B_log(ctx context.Context, b string) int {
b = strings.ToUpper(b)
tellog.Print(ctx, "b uppercased, so lowercased", tag.Of("len_b", len(b)))
if len(b) > 1024 {
b = strings.ToLower(b)
tellog.Print(ctx, "b > 1024, so lowercased", tag.Of("b", b))
}
return len(b)
}
func A_trace(ctx context.Context, a int) int {
ctx, done := teltrace.StartSpan(ctx, "A")
defer done()
if a > 0 {
_ = 10 * 12
}
return B_trace(ctx, "Called from A")
}
func B_trace(ctx context.Context, b string) int {
ctx, done := teltrace.StartSpan(ctx, "B")
defer done()
b = strings.ToUpper(b)
if len(b) > 1024 {
b = strings.ToLower(b)
}
return len(b)
}
func A_log_stdlib(ctx context.Context, a int) int {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
if a > 0 {
stdlog.Printf("a > 0 where a=%d", a)
_ = 10 * 12
}
stdlog.Print("calling b")
return B_log_stdlib(ctx, "Called from A")
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
}
func B_log_stdlib(ctx context.Context, b string) int {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b = strings.ToUpper(b)
stdlog.Printf("b uppercased, so lowercased where len_b=%d", len(b))
if len(b) > 1024 {
b = strings.ToLower(b)
stdlog.Printf("b > 1024, so lowercased where b=%s", b)
}
return len(b)
}
var values = []int{0, 10, 20, 100, 1000}
type loggingExporter struct {
logger export.Exporter
}
func newExporter() *loggingExporter {
return &loggingExporter{
logger: export.LogWriter(new(noopWriter), false),
}
}
func (e *loggingExporter) ProcessEvent(ctx context.Context, event telemetry.Event) context.Context {
export.ContextSpan(ctx, event)
return e.logger.ProcessEvent(ctx, event)
}
func (e *loggingExporter) Metric(ctx context.Context, data telemetry.MetricData) {
e.logger.Metric(ctx, data)
}
func BenchmarkBaseline(b *testing.B) {
ctx := context.Background()
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.ReportAllocs()
b.ResetTimer()
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A(ctx, value); g <= 0 {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}
func BenchmarkLoggingNoExporter(b *testing.B) {
ctx := context.Background()
export.SetExporter(nil)
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A_log(ctx, value); g <= 0 {
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}
func BenchmarkLogging(b *testing.B) {
ctx := context.Background()
export.SetExporter(newExporter())
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.ReportAllocs()
b.ResetTimer()
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A_log(ctx, value); g <= 0 {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}
func BenchmarkTracingNoExporter(b *testing.B) {
ctx := context.Background()
export.SetExporter(nil)
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A_trace(ctx, value); g <= 0 {
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}
func BenchmarkTracing(b *testing.B) {
ctx := context.Background()
export.SetExporter(newExporter())
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A_trace(ctx, value); g <= 0 {
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
func BenchmarkLoggingStdlib(b *testing.B) {
ctx := context.Background()
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.ReportAllocs()
b.ResetTimer()
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
for i := 0; i < b.N; i++ {
for _, value := range values {
if g := A_log_stdlib(ctx, value); g <= 0 {
telemetry/log: sample reference for benchmarking harness Serves as a reference harness to get benchmarking started. Steps to run benchmark: $ go test -run=^$ -bench=. -count=10 After you grab the output, put the various comparisons into files before.txt and after.txt then edit those result names to have a common name e.g. s/BenchmarkLoggingNoExporter/BenchmarkIt/g s/BenchmarkNoTracingNoMetricsNoLogging/BenchmarkIt/g s/BenchmarkLoggingStdlib/BenchmarkIt/g Now run benchstat: * All compared $ benchstat no_log.txt tellog.txt stdlog.txt name \ time/op no_log.txt tellog.txt stdlog.txt It-8 289ns ± 2% 2780ns ± 3% 5100ns ± 3% name \ alloc/op no_log.txt tellog.txt stdlog.txt It-8 80.0B ± 0% 728.0B ± 0% 568.0B ± 0% name \ allocs/op no_log.txt tellog.txt stdlog.txt It-8 5.00 ± 0% 32.00 ± 0% 28.00 ± 0% * No logging vs telemetry log $ benchstat no_log.txt tellog.txt name old time/op new time/op delta It-8 289ns ± 2% 2780ns ± 3% +862.31% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 728.0B ± 0% +810.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 32.00 ± 0% +540.00% (p=0.000 n=10+10) * No logging vs Standard library "log" $ benchstat no_log.txt stdlog.txt name old time/op new time/op delta It-8 289ns ± 2% 5100ns ± 3% +1665.16% (p=0.000 n=10+9) name old alloc/op new alloc/op delta It-8 80.0B ± 0% 568.0B ± 0% +610.00% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 5.00 ± 0% 28.00 ± 0% +460.00% (p=0.000 n=10+10) * telemetry log vs Standard library "log" $ benchstat tellog.txt stdlog.txt name old time/op new time/op delta It-8 2.78µs ± 3% 5.10µs ± 3% +83.43% (p=0.000 n=9+9) name old alloc/op new alloc/op delta It-8 728B ± 0% 568B ± 0% -21.98% (p=0.000 n=10+10) name old allocs/op new allocs/op delta It-8 32.0 ± 0% 28.0 ± 0% -12.50% (p=0.000 n=10+10) Change-Id: I53b15e9da315615278c576f3a60108435417a9f7 Reviewed-on: https://go-review.googlesource.com/c/tools/+/212078 Run-TryBot: Emmanuel Odeke <emm.odeke@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Cottrell <iancottrell@google.com>
2019-12-19 09:57:21 -07:00
b.Fatalf("Unexpected got g(%d) <= 0", g)
}
}
}
}