diff options
author | Hana Kim <hakim@google.com> | 2018-04-24 12:42:47 -0400 |
---|---|---|
committer | Hyang-Ah Hana Kim <hyangah@gmail.com> | 2018-04-24 17:43:19 +0000 |
commit | 3bf16444283094bf03a96fa76f3c5dd4c84867b2 (patch) | |
tree | a47f63e867d3d91435fe509070b04cdebd03d7c7 /src/runtime/trace | |
parent | c2d10243688194346f660591fe4159e30a8d20ec (diff) | |
download | go-3bf16444283094bf03a96fa76f3c5dd4c84867b2.tar.gz go-3bf16444283094bf03a96fa76f3c5dd4c84867b2.zip |
runtime/trace: add simple benchmarks for user annotation
Also, avoid Region creation when tracing is disabled.
Unfortunate side-effect of this change is that we no longer trace
pre-existing regions in tracing, but we can add the feature in
the future when we find it useful and justifiable. Until then,
let's avoid the overhead from this low-level api use as much as
possible.
goos: linux
goarch: amd64
pkg: runtime/trace
// Trace disabled
BenchmarkStartRegion-12 2000000000 0.66 ns/op 0 B/op 0 allocs/op
BenchmarkNewTask-12 30000000 40.4 ns/op 56 B/op 2 allocs/op
// Trace enabled, -trace=/dev/null
BenchmarkStartRegion-12 5000000 287 ns/op 32 B/op 1 allocs/op
BenchmarkNewTask-12 5000000 283 ns/op 56 B/op 2 allocs/op
Also, skip other tests if tracing is already enabled.
Change-Id: Id3028d60b5642fcab4b09a74fd7d79361a3861e5
Reviewed-on: https://go-review.googlesource.com/109115
Reviewed-by: Peter Weinberger <pjw@google.com>
Diffstat (limited to 'src/runtime/trace')
-rw-r--r-- | src/runtime/trace/annotation.go | 8 | ||||
-rw-r--r-- | src/runtime/trace/annotation_test.go | 31 | ||||
-rw-r--r-- | src/runtime/trace/trace_stack_test.go | 9 | ||||
-rw-r--r-- | src/runtime/trace/trace_test.go | 21 |
4 files changed, 67 insertions, 2 deletions
diff --git a/src/runtime/trace/annotation.go b/src/runtime/trace/annotation.go index 0261d1c162..1cf01165cc 100644 --- a/src/runtime/trace/annotation.go +++ b/src/runtime/trace/annotation.go @@ -158,6 +158,9 @@ func WithSpan(ctx context.Context, spanType string, fn func(ctx context.Context) // defer trace.StartRegion(ctx, "myTracedRegion").End() // func StartRegion(ctx context.Context, regionType string) *Region { + if !IsEnabled() { + return noopRegion + } id := fromContext(ctx).id userRegion(id, regionStartCode, regionType) return &Region{id, regionType} @@ -175,8 +178,13 @@ type Region struct { regionType string } +var noopRegion = &Region{} + // End marks the end of the traced code region. func (r *Region) End() { + if r == noopRegion { + return + } userRegion(r.id, regionEndCode, r.regionType) } diff --git a/src/runtime/trace/annotation_test.go b/src/runtime/trace/annotation_test.go index c20b009daa..71abbfcfa6 100644 --- a/src/runtime/trace/annotation_test.go +++ b/src/runtime/trace/annotation_test.go @@ -12,7 +12,35 @@ import ( "testing" ) +func BenchmarkStartRegion(b *testing.B) { + b.ReportAllocs() + ctx, task := NewTask(context.Background(), "benchmark") + defer task.End() + + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + StartRegion(ctx, "region").End() + } + }) +} + +func BenchmarkNewTask(b *testing.B) { + b.ReportAllocs() + pctx, task := NewTask(context.Background(), "benchmark") + defer task.End() + + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + _, task := NewTask(pctx, "task") + task.End() + } + }) +} + func TestUserTaskRegion(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } bgctx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -107,7 +135,8 @@ func TestUserTaskRegion(t *testing.T) { {trace.EvUserRegion, []string{"task0", "region1"}, []uint64{1}, false}, {trace.EvUserRegion, []string{"task0", "region0"}, []uint64{1}, false}, {trace.EvUserTaskEnd, []string{"task0"}, nil, false}, - {trace.EvUserRegion, []string{"", "pre-existing region"}, []uint64{1}, false}, + // Currently, pre-existing region is not recorded to avoid allocations. + // {trace.EvUserRegion, []string{"", "pre-existing region"}, []uint64{1}, false}, {trace.EvUserRegion, []string{"", "post-existing region"}, []uint64{0}, false}, } if !reflect.DeepEqual(got, want) { diff --git a/src/runtime/trace/trace_stack_test.go b/src/runtime/trace/trace_stack_test.go index e7b8d57659..62c06e67d9 100644 --- a/src/runtime/trace/trace_stack_test.go +++ b/src/runtime/trace/trace_stack_test.go @@ -24,7 +24,7 @@ import ( // In particular that we strip bottom uninteresting frames like goexit, // top uninteresting frames (runtime guts). func TestTraceSymbolize(t *testing.T) { - testenv.MustHaveGoBuild(t) + skipTraceSymbolizeTestIfNecessary(t) buf := new(bytes.Buffer) if err := Start(buf); err != nil { @@ -285,6 +285,13 @@ func TestTraceSymbolize(t *testing.T) { } } +func skipTraceSymbolizeTestIfNecessary(t *testing.T) { + testenv.MustHaveGoBuild(t) + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } +} + func dumpEventStacks(typ byte, events []*trace.Event) ([]byte, int) { matched := 0 o := new(bytes.Buffer) diff --git a/src/runtime/trace/trace_test.go b/src/runtime/trace/trace_test.go index 997d486c65..f289bd6f85 100644 --- a/src/runtime/trace/trace_test.go +++ b/src/runtime/trace/trace_test.go @@ -31,6 +31,9 @@ func TestEventBatch(t *testing.T) { if race.Enabled { t.Skip("skipping in race mode") } + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } if testing.Short() { t.Skip("skipping in short mode") } @@ -81,6 +84,9 @@ func TestEventBatch(t *testing.T) { } func TestTraceStartStop(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } buf := new(bytes.Buffer) if err := Start(buf); err != nil { t.Fatalf("failed to start tracing: %v", err) @@ -98,6 +104,9 @@ func TestTraceStartStop(t *testing.T) { } func TestTraceDoubleStart(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } Stop() buf := new(bytes.Buffer) if err := Start(buf); err != nil { @@ -111,6 +120,9 @@ func TestTraceDoubleStart(t *testing.T) { } func TestTrace(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } buf := new(bytes.Buffer) if err := Start(buf); err != nil { t.Fatalf("failed to start tracing: %v", err) @@ -168,6 +180,9 @@ func testBrokenTimestamps(t *testing.T, data []byte) { } func TestTraceStress(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } var wg sync.WaitGroup done := make(chan bool) @@ -307,6 +322,9 @@ func TestTraceStress(t *testing.T) { // Do a bunch of various stuff (timers, GC, network, etc) in a separate goroutine. // And concurrently with all that start/stop trace 3 times. func TestTraceStressStartStop(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(8)) outerDone := make(chan bool) @@ -454,6 +472,9 @@ func TestTraceStressStartStop(t *testing.T) { } func TestTraceFutileWakeup(t *testing.T) { + if IsEnabled() { + t.Skip("skipping because -test.trace is set") + } buf := new(bytes.Buffer) if err := Start(buf); err != nil { t.Fatalf("failed to start tracing: %v", err) |