diff --git a/internal/telemetry/bench_test.go b/internal/telemetry/bench_test.go index 8145e9fcd2..4dc2d9b69b 100644 --- a/internal/telemetry/bench_test.go +++ b/internal/telemetry/bench_test.go @@ -13,6 +13,104 @@ import ( teltrace "golang.org/x/tools/internal/telemetry/trace" ) +type Hooks struct { + A func(ctx context.Context, a *int) (context.Context, func()) + B func(ctx context.Context, b *string) (context.Context, func()) +} + +var ( + Baseline = Hooks{ + A: func(ctx context.Context, a *int) (context.Context, func()) { + return ctx, func() {} + }, + B: func(ctx context.Context, b *string) (context.Context, func()) { + return ctx, func() {} + }, + } + + StdLog = Hooks{ + A: func(ctx context.Context, a *int) (context.Context, func()) { + stdlog.Printf("start A where a=%d", *a) + return ctx, func() { + stdlog.Printf("end A where a=%d", *a) + } + }, + B: func(ctx context.Context, b *string) (context.Context, func()) { + stdlog.Printf("start B where b=%q", *b) + return ctx, func() { + stdlog.Printf("end B where b=%q", *b) + } + }, + } + + Log = Hooks{ + A: func(ctx context.Context, a *int) (context.Context, func()) { + tellog.Print(ctx, "start A", tag.Of("a", *a)) + return ctx, func() { + tellog.Print(ctx, "end A", tag.Of("a", *a)) + } + }, + B: func(ctx context.Context, b *string) (context.Context, func()) { + tellog.Print(ctx, "start B", tag.Of("b", *b)) + return ctx, func() { + tellog.Print(ctx, "end B", tag.Of("b", *b)) + } + }, + } + + Trace = Hooks{ + A: func(ctx context.Context, a *int) (context.Context, func()) { + return teltrace.StartSpan(ctx, "A") + }, + B: func(ctx context.Context, b *string) (context.Context, func()) { + return teltrace.StartSpan(ctx, "B") + }, + } +) + +func Benchmark(b *testing.B) { + b.Run("Baseline", Baseline.runBenchmark) + b.Run("StdLog", StdLog.runBenchmark) + export.SetExporter(nil) + b.Run("LogNoExporter", Log.runBenchmark) + b.Run("TraceNoExporter", Trace.runBenchmark) + + export.SetExporter(newExporter()) + b.Run("Log", Log.runBenchmark) + b.Run("Trace", Trace.runBenchmark) +} + +func A(ctx context.Context, hooks Hooks, a int) int { + ctx, done := hooks.A(ctx, &a) + defer done() + if a > 0 { + a = a * 10 + } + return B(ctx, hooks, a, "Called from A") +} + +func B(ctx context.Context, hooks Hooks, a int, b string) int { + _, done := hooks.B(ctx, &b) + defer done() + b = strings.ToUpper(b) + if len(b) > 1024 { + b = strings.ToLower(b) + } + return a + len(b) +} + +func (hooks Hooks) runBenchmark(b *testing.B) { + ctx := context.Background() + b.ReportAllocs() + b.ResetTimer() + var acc int + for i := 0; i < b.N; i++ { + for _, value := range []int{0, 10, 20, 100, 1000} { + acc += A(ctx, hooks, value) + } + } +} + func init() { stdlog.SetOutput(new(noopWriter)) } @@ -23,79 +121,6 @@ func (nw *noopWriter) Write(b []byte) (int, error) { return len(b), nil } -func A(ctx context.Context, a int) int { - if a > 0 { - _ = 10 * 12 - } - return B(ctx, "Called from A") -} - -func B(ctx context.Context, b string) int { - 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 { - 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") -} - -func B_log_stdlib(ctx context.Context, b string) int { - 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 } @@ -114,84 +139,3 @@ func (e *loggingExporter) ProcessEvent(ctx context.Context, event telemetry.Even func (e *loggingExporter) Metric(ctx context.Context, data telemetry.MetricData) { e.logger.Metric(ctx, data) } - -func BenchmarkBaseline(b *testing.B) { - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - for _, value := range values { - if g := A(ctx, value); g <= 0 { - 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()) - 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 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) - } - } - } -} - -func BenchmarkLoggingStdlib(b *testing.B) { - ctx := context.Background() - b.ReportAllocs() - b.ResetTimer() - for i := 0; i < b.N; i++ { - for _, value := range values { - if g := A_log_stdlib(ctx, value); g <= 0 { - b.Fatalf("Unexpected got g(%d) <= 0", g) - } - } - } -}