github.com/megatontech/mynoteforgo@v0.0.0-20200507084910-5d0c6ea6e890/源码/cmd/trace/trace_test.go (about) 1 // Copyright 2016 The Go Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style 3 // license that can be found in the LICENSE file. 4 5 // +build !js 6 7 package main 8 9 import ( 10 "context" 11 "internal/trace" 12 "io/ioutil" 13 rtrace "runtime/trace" 14 "strings" 15 "testing" 16 ) 17 18 // stacks is a fake stack map populated for test. 19 type stacks map[uint64][]*trace.Frame 20 21 // add adds a stack with a single frame whose Fn field is 22 // set to the provided fname and returns a unique stack id. 23 func (s *stacks) add(fname string) uint64 { 24 if *s == nil { 25 *s = make(map[uint64][]*trace.Frame) 26 } 27 28 id := uint64(len(*s)) 29 (*s)[id] = []*trace.Frame{{Fn: fname}} 30 return id 31 } 32 33 // TestGoroutineCount tests runnable/running goroutine counts computed by generateTrace 34 // remain in the valid range. 35 // - the counts must not be negative. generateTrace will return an error. 36 // - the counts must not include goroutines blocked waiting on channels or in syscall. 37 func TestGoroutineCount(t *testing.T) { 38 w := trace.NewWriter() 39 w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp] 40 w.Emit(trace.EvFrequency, 1) // [ticks per second] 41 42 var s stacks 43 44 // In this test, we assume a valid trace contains EvGoWaiting or EvGoInSyscall 45 // event for every blocked goroutine. 46 47 // goroutine 10: blocked 48 w.Emit(trace.EvGoCreate, 1, 10, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id] 49 w.Emit(trace.EvGoWaiting, 1, 10) // [timestamp, goroutine id] 50 51 // goroutine 20: in syscall 52 w.Emit(trace.EvGoCreate, 1, 20, s.add("pkg.f2"), s.add("main.f2")) 53 w.Emit(trace.EvGoInSyscall, 1, 20) // [timestamp, goroutine id] 54 55 // goroutine 30: runnable 56 w.Emit(trace.EvGoCreate, 1, 30, s.add("pkg.f3"), s.add("main.f3")) 57 58 w.Emit(trace.EvProcStart, 2, 0) // [timestamp, thread id] 59 60 // goroutine 40: runnable->running->runnable 61 w.Emit(trace.EvGoCreate, 1, 40, s.add("pkg.f4"), s.add("main.f4")) 62 w.Emit(trace.EvGoStartLocal, 1, 40) // [timestamp, goroutine id] 63 w.Emit(trace.EvGoSched, 1, s.add("main.f4")) // [timestamp, stack] 64 65 res, err := trace.Parse(w, "") 66 if err != nil { 67 t.Fatalf("failed to parse test trace: %v", err) 68 } 69 res.Stacks = s // use fake stacks. 70 71 params := &traceParams{ 72 parsed: res, 73 endTime: int64(1<<63 - 1), 74 } 75 76 // Use the default viewerDataTraceConsumer but replace 77 // consumeViewerEvent to intercept the ViewerEvents for testing. 78 c := viewerDataTraceConsumer(ioutil.Discard, 0, 1<<63-1) 79 c.consumeViewerEvent = func(ev *ViewerEvent, _ bool) { 80 if ev.Name == "Goroutines" { 81 cnt := ev.Arg.(*goroutineCountersArg) 82 if cnt.Runnable+cnt.Running > 2 { 83 t.Errorf("goroutine count=%+v; want no more than 2 goroutines in runnable/running state", cnt) 84 } 85 t.Logf("read %+v %+v", ev, cnt) 86 } 87 } 88 89 // If the counts drop below 0, generateTrace will return an error. 90 if err := generateTrace(params, c); err != nil { 91 t.Fatalf("generateTrace failed: %v", err) 92 } 93 } 94 95 func TestGoroutineFilter(t *testing.T) { 96 // Test that we handle state changes to selected goroutines 97 // caused by events on goroutines that are not selected. 98 99 var s stacks 100 101 w := trace.NewWriter() 102 w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp] 103 w.Emit(trace.EvFrequency, 1) // [ticks per second] 104 105 // goroutine 10: blocked 106 w.Emit(trace.EvGoCreate, 1, 10, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id] 107 w.Emit(trace.EvGoWaiting, 1, 10) // [timestamp, goroutine id] 108 109 // goroutine 20: runnable->running->unblock 10 110 w.Emit(trace.EvGoCreate, 1, 20, s.add("pkg.f2"), s.add("main.f2")) 111 w.Emit(trace.EvGoStartLocal, 1, 20) // [timestamp, goroutine id] 112 w.Emit(trace.EvGoUnblockLocal, 1, 10, s.add("pkg.f2")) // [timestamp, goroutine id, stack] 113 w.Emit(trace.EvGoEnd, 1) // [timestamp] 114 115 // goroutine 10: runnable->running->block 116 w.Emit(trace.EvGoStartLocal, 1, 10) // [timestamp, goroutine id] 117 w.Emit(trace.EvGoBlock, 1, s.add("pkg.f3")) // [timestamp, stack] 118 119 res, err := trace.Parse(w, "") 120 if err != nil { 121 t.Fatalf("failed to parse test trace: %v", err) 122 } 123 res.Stacks = s // use fake stacks 124 125 params := &traceParams{ 126 parsed: res, 127 endTime: int64(1<<63 - 1), 128 gs: map[uint64]bool{10: true}, 129 } 130 131 c := viewerDataTraceConsumer(ioutil.Discard, 0, 1<<63-1) 132 if err := generateTrace(params, c); err != nil { 133 t.Fatalf("generateTrace failed: %v", err) 134 } 135 } 136 137 func TestPreemptedMarkAssist(t *testing.T) { 138 w := trace.NewWriter() 139 w.Emit(trace.EvBatch, 0, 0) // start of per-P batch event [pid, timestamp] 140 w.Emit(trace.EvFrequency, 1) // [ticks per second] 141 142 var s stacks 143 // goroutine 9999: running -> mark assisting -> preempted -> assisting -> running -> block 144 w.Emit(trace.EvGoCreate, 1, 9999, s.add("pkg.f1"), s.add("main.f1")) // [timestamp, new goroutine id, new stack id, stack id] 145 w.Emit(trace.EvGoStartLocal, 1, 9999) // [timestamp, goroutine id] 146 w.Emit(trace.EvGCMarkAssistStart, 1, s.add("main.f1")) // [timestamp, stack] 147 w.Emit(trace.EvGoPreempt, 1, s.add("main.f1")) // [timestamp, stack] 148 w.Emit(trace.EvGoStartLocal, 1, 9999) // [timestamp, goroutine id] 149 w.Emit(trace.EvGCMarkAssistDone, 1) // [timestamp] 150 w.Emit(trace.EvGoBlock, 1, s.add("main.f2")) // [timestamp, stack] 151 152 res, err := trace.Parse(w, "") 153 if err != nil { 154 t.Fatalf("failed to parse test trace: %v", err) 155 } 156 res.Stacks = s // use fake stacks 157 158 params := &traceParams{ 159 parsed: res, 160 endTime: int64(1<<63 - 1), 161 } 162 163 c := viewerDataTraceConsumer(ioutil.Discard, 0, 1<<63-1) 164 165 marks := 0 166 c.consumeViewerEvent = func(ev *ViewerEvent, _ bool) { 167 if strings.Contains(ev.Name, "MARK ASSIST") { 168 marks++ 169 } 170 } 171 if err := generateTrace(params, c); err != nil { 172 t.Fatalf("generateTrace failed: %v", err) 173 } 174 175 if marks != 2 { 176 t.Errorf("Got %v MARK ASSIST events, want %v", marks, 2) 177 } 178 } 179 180 func TestFoo(t *testing.T) { 181 prog0 := func() { 182 ctx, task := rtrace.NewTask(context.Background(), "ohHappyDay") 183 rtrace.Log(ctx, "", "log before task ends") 184 task.End() 185 rtrace.Log(ctx, "", "log after task ends") // log after task ends 186 } 187 if err := traceProgram(t, prog0, "TestFoo"); err != nil { 188 t.Fatalf("failed to trace the program: %v", err) 189 } 190 res, err := parseTrace() 191 if err != nil { 192 t.Fatalf("failed to parse the trace: %v", err) 193 } 194 annotRes, _ := analyzeAnnotations() 195 var task *taskDesc 196 for _, t := range annotRes.tasks { 197 if t.name == "ohHappyDay" { 198 task = t 199 break 200 } 201 } 202 if task == nil { 203 t.Fatal("failed to locate expected task event") 204 } 205 206 params := &traceParams{ 207 parsed: res, 208 mode: modeTaskOriented, 209 startTime: task.firstTimestamp() - 1, 210 endTime: task.lastTimestamp() + 1, 211 tasks: []*taskDesc{task}, 212 } 213 214 c := viewerDataTraceConsumer(ioutil.Discard, 0, 1<<63-1) 215 216 var logBeforeTaskEnd, logAfterTaskEnd bool 217 c.consumeViewerEvent = func(ev *ViewerEvent, _ bool) { 218 if ev.Name == "log before task ends" { 219 logBeforeTaskEnd = true 220 } 221 if ev.Name == "log after task ends" { 222 logAfterTaskEnd = true 223 } 224 } 225 if err := generateTrace(params, c); err != nil { 226 t.Fatalf("generateTrace failed: %v", err) 227 } 228 if !logBeforeTaskEnd { 229 t.Error("failed to find 'log before task ends'") 230 } 231 if !logAfterTaskEnd { 232 t.Error("failed to find 'log after task ends'") 233 } 234 235 }