summaryrefslogtreecommitdiffstats
path: root/src/cmd/trace/trace_test.go
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--src/cmd/trace/trace_test.go269
1 files changed, 269 insertions, 0 deletions
diff --git a/src/cmd/trace/trace_test.go b/src/cmd/trace/trace_test.go
new file mode 100644
index 0000000..ea0cc6f
--- /dev/null
+++ b/src/cmd/trace/trace_test.go
@@ -0,0 +1,269 @@
+// Copyright 2016 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+// +build !js
+
+package main
+
+import (
+ "cmd/internal/traceviewer"
+ "context"
+ "internal/trace"
+ "io"
+ rtrace "runtime/trace"
+ "strings"
+ "sync"
+ "testing"
+ "time"
+)
+
+// stacks is a fake stack map populated for test.
+type stacks map[uint64][]*trace.Frame
+
+// add adds a stack with a single frame whose Fn field is
+// set to the provided fname and returns a unique stack id.
+func (s *stacks) add(fname string) uint64 {
+ if *s == nil {
+ *s = make(map[uint64][]*trace.Frame)
+ }
+
+ id := uint64(len(*s))
+ (*s)[id] = []*trace.Frame{{Fn: fname}}
+ return id
+}
+
+// TestGoroutineCount tests runnable/running goroutine counts computed by generateTrace
+// remain in the valid range.
+// - the counts must not be negative. generateTrace will return an error.
+// - the counts must not include goroutines blocked waiting on channels or in syscall.
+func TestGoroutineCount(t *testing.T) {
+ w := trace.NewWriter()
+ w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp]
+ w.Emit(trace.EvFrequency, 1) // [ticks per second]
+
+ var s stacks
+
+ // In this test, we assume a valid trace contains EvGoWaiting or EvGoInSyscall
+ // event for every blocked goroutine.
+
+ // goroutine 10: blocked
+ w.Emit(trace.EvGoCreate, 1, 10, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id]
+ w.Emit(trace.EvGoWaiting, 1, 10) // [timestamp, goroutine id]
+
+ // goroutine 20: in syscall
+ w.Emit(trace.EvGoCreate, 1, 20, s.add("pkg.f2"), s.add("main.f2"))
+ w.Emit(trace.EvGoInSyscall, 1, 20) // [timestamp, goroutine id]
+
+ // goroutine 30: runnable
+ w.Emit(trace.EvGoCreate, 1, 30, s.add("pkg.f3"), s.add("main.f3"))
+
+ w.Emit(trace.EvProcStart, 2, 0) // [timestamp, thread id]
+
+ // goroutine 40: runnable->running->runnable
+ w.Emit(trace.EvGoCreate, 1, 40, s.add("pkg.f4"), s.add("main.f4"))
+ w.Emit(trace.EvGoStartLocal, 1, 40) // [timestamp, goroutine id]
+ w.Emit(trace.EvGoSched, 1, s.add("main.f4")) // [timestamp, stack]
+
+ res, err := trace.Parse(w, "")
+ if err != nil {
+ t.Fatalf("failed to parse test trace: %v", err)
+ }
+ res.Stacks = s // use fake stacks.
+
+ params := &traceParams{
+ parsed: res,
+ endTime: int64(1<<63 - 1),
+ }
+
+ // Use the default viewerDataTraceConsumer but replace
+ // consumeViewerEvent to intercept the ViewerEvents for testing.
+ c := viewerDataTraceConsumer(io.Discard, 0, 1<<63-1)
+ c.consumeViewerEvent = func(ev *traceviewer.Event, _ bool) {
+ if ev.Name == "Goroutines" {
+ cnt := ev.Arg.(*goroutineCountersArg)
+ if cnt.Runnable+cnt.Running > 2 {
+ t.Errorf("goroutine count=%+v; want no more than 2 goroutines in runnable/running state", cnt)
+ }
+ t.Logf("read %+v %+v", ev, cnt)
+ }
+ }
+
+ // If the counts drop below 0, generateTrace will return an error.
+ if err := generateTrace(params, c); err != nil {
+ t.Fatalf("generateTrace failed: %v", err)
+ }
+}
+
+func TestGoroutineFilter(t *testing.T) {
+ // Test that we handle state changes to selected goroutines
+ // caused by events on goroutines that are not selected.
+
+ var s stacks
+
+ w := trace.NewWriter()
+ w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp]
+ w.Emit(trace.EvFrequency, 1) // [ticks per second]
+
+ // goroutine 10: blocked
+ w.Emit(trace.EvGoCreate, 1, 10, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id]
+ w.Emit(trace.EvGoWaiting, 1, 10) // [timestamp, goroutine id]
+
+ // goroutine 20: runnable->running->unblock 10
+ w.Emit(trace.EvGoCreate, 1, 20, s.add("pkg.f2"), s.add("main.f2"))
+ w.Emit(trace.EvGoStartLocal, 1, 20) // [timestamp, goroutine id]
+ w.Emit(trace.EvGoUnblockLocal, 1, 10, s.add("pkg.f2")) // [timestamp, goroutine id, stack]
+ w.Emit(trace.EvGoEnd, 1) // [timestamp]
+
+ // goroutine 10: runnable->running->block
+ w.Emit(trace.EvGoStartLocal, 1, 10) // [timestamp, goroutine id]
+ w.Emit(trace.EvGoBlock, 1, s.add("pkg.f3")) // [timestamp, stack]
+
+ res, err := trace.Parse(w, "")
+ if err != nil {
+ t.Fatalf("failed to parse test trace: %v", err)
+ }
+ res.Stacks = s // use fake stacks
+
+ params := &traceParams{
+ parsed: res,
+ endTime: int64(1<<63 - 1),
+ gs: map[uint64]bool{10: true},
+ }
+
+ c := viewerDataTraceConsumer(io.Discard, 0, 1<<63-1)
+ if err := generateTrace(params, c); err != nil {
+ t.Fatalf("generateTrace failed: %v", err)
+ }
+}
+
+func TestPreemptedMarkAssist(t *testing.T) {
+ w := trace.NewWriter()
+ w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp]
+ w.Emit(trace.EvFrequency, 1) // [ticks per second]
+
+ var s stacks
+ // goroutine 9999: running -> mark assisting -> preempted -> assisting -> running -> block
+ w.Emit(trace.EvGoCreate, 1, 9999, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id]
+ w.Emit(trace.EvGoStartLocal, 1, 9999) // [timestamp, goroutine id]
+ w.Emit(trace.EvGCMarkAssistStart, 1, s.add("main.f1")) // [timestamp, stack]
+ w.Emit(trace.EvGoPreempt, 1, s.add("main.f1")) // [timestamp, stack]
+ w.Emit(trace.EvGoStartLocal, 1, 9999) // [timestamp, goroutine id]
+ w.Emit(trace.EvGCMarkAssistDone, 1) // [timestamp]
+ w.Emit(trace.EvGoBlock, 1, s.add("main.f2")) // [timestamp, stack]
+
+ res, err := trace.Parse(w, "")
+ if err != nil {
+ t.Fatalf("failed to parse test trace: %v", err)
+ }
+ res.Stacks = s // use fake stacks
+
+ params := &traceParams{
+ parsed: res,
+ endTime: int64(1<<63 - 1),
+ }
+
+ c := viewerDataTraceConsumer(io.Discard, 0, 1<<63-1)
+
+ marks := 0
+ c.consumeViewerEvent = func(ev *traceviewer.Event, _ bool) {
+ if strings.Contains(ev.Name, "MARK ASSIST") {
+ marks++
+ }
+ }
+ if err := generateTrace(params, c); err != nil {
+ t.Fatalf("generateTrace failed: %v", err)
+ }
+
+ if marks != 2 {
+ t.Errorf("Got %v MARK ASSIST events, want %v", marks, 2)
+ }
+}
+
+func TestFoo(t *testing.T) {
+ prog0 := func() {
+ ctx, task := rtrace.NewTask(context.Background(), "ohHappyDay")
+ rtrace.Log(ctx, "", "log before task ends")
+ task.End()
+ rtrace.Log(ctx, "", "log after task ends") // log after task ends
+ }
+ if err := traceProgram(t, prog0, "TestFoo"); err != nil {
+ t.Fatalf("failed to trace the program: %v", err)
+ }
+ res, err := parseTrace()
+ if err != nil {
+ t.Fatalf("failed to parse the trace: %v", err)
+ }
+ annotRes, _ := analyzeAnnotations()
+ var task *taskDesc
+ for _, t := range annotRes.tasks {
+ if t.name == "ohHappyDay" {
+ task = t
+ break
+ }
+ }
+ if task == nil {
+ t.Fatal("failed to locate expected task event")
+ }
+
+ params := &traceParams{
+ parsed: res,
+ mode: modeTaskOriented,
+ startTime: task.firstTimestamp() - 1,
+ endTime: task.lastTimestamp() + 1,
+ tasks: []*taskDesc{task},
+ }
+
+ c := viewerDataTraceConsumer(io.Discard, 0, 1<<63-1)
+
+ var logBeforeTaskEnd, logAfterTaskEnd bool
+ c.consumeViewerEvent = func(ev *traceviewer.Event, _ bool) {
+ if ev.Name == "log before task ends" {
+ logBeforeTaskEnd = true
+ }
+ if ev.Name == "log after task ends" {
+ logAfterTaskEnd = true
+ }
+ }
+ if err := generateTrace(params, c); err != nil {
+ t.Fatalf("generateTrace failed: %v", err)
+ }
+ if !logBeforeTaskEnd {
+ t.Error("failed to find 'log before task ends'")
+ }
+ if !logAfterTaskEnd {
+ t.Error("failed to find 'log after task ends'")
+ }
+
+}
+
+func TestDirectSemaphoreHandoff(t *testing.T) {
+ prog0 := func() {
+ var mu sync.Mutex
+ var wg sync.WaitGroup
+ mu.Lock()
+ // This is modeled after src/sync/mutex_test.go to trigger Mutex
+ // starvation mode, in which the goroutine that calls Unlock hands off
+ // both the semaphore and its remaining time slice. See issue 36186.
+ for i := 0; i < 2; i++ {
+ wg.Add(1)
+ go func() {
+ defer wg.Done()
+ for i := 0; i < 100; i++ {
+ mu.Lock()
+ time.Sleep(100 * time.Microsecond)
+ mu.Unlock()
+ }
+ }()
+ }
+ mu.Unlock()
+ wg.Wait()
+ }
+ if err := traceProgram(t, prog0, "TestDirectSemaphoreHandoff"); err != nil {
+ t.Fatalf("failed to trace the program: %v", err)
+ }
+ _, err := parseTrace()
+ if err != nil {
+ t.Fatalf("failed to parse the trace: %v", err)
+ }
+}