1 // Copyright 2014 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.
20 // TestTraceSymbolize tests symbolization and that events has proper stacks.
21 // In particular that we strip bottom uninteresting frames like goexit,
22 // top uninteresting frames (runtime guts).
23 func TestTraceSymbolize(t *testing.T) {
24 testenv.MustHaveExec(t)
26 buf := new(bytes.Buffer)
27 if err := Start(buf); err != nil {
28 t.Fatalf("failed to start tracing: %v", err)
30 defer Stop() // in case of early return
32 // Now we will do a bunch of things for which we verify stacks later.
33 // It is impossible to ensure that a goroutine has actually blocked
34 // on a channel, in a select or otherwise. So we kick off goroutines
35 // that need to block first in the hope that while we are executing
36 // the rest of the test, they will block.
48 done1 := make(chan bool)
52 done2 := make(chan bool)
75 cv := sync.NewCond(&sync.Mutex{})
81 ln, err := net.Listen("tcp", "127.0.0.1:0")
83 t.Fatalf("failed to listen: %v", err)
88 t.Fatalf("failed to accept: %v", err)
92 rp, wp, err := os.Pipe()
94 t.Fatalf("failed to create a pipe: %v", err)
98 pipeReadDone := make(chan bool)
105 time.Sleep(time.Millisecond)
108 time.Sleep(time.Millisecond) // the last chance for the goroutines above to block
118 c, err := net.Dial("tcp", ln.Addr().String())
120 t.Fatalf("failed to dial: %v", err)
128 events, _, err := parseTrace(t, buf)
130 t.Fatalf("failed to parse trace: %v", err)
132 err = trace.Symbolize(events, os.Args[0])
134 t.Fatalf("failed to symbolize trace: %v", err)
137 // Now check that the stacks are correct.
142 type eventDesc struct {
147 eventDesc{trace.EvGCStart, []frame{
148 frame{"runtime.GC", 0},
149 frame{"runtime/trace_test.TestTraceSymbolize", 106},
150 frame{"testing.tRunner", 0},
152 eventDesc{trace.EvGoSched, []frame{
153 frame{"runtime/trace_test.TestTraceSymbolize", 107},
154 frame{"testing.tRunner", 0},
156 eventDesc{trace.EvGoCreate, []frame{
157 frame{"runtime/trace_test.TestTraceSymbolize", 39},
158 frame{"testing.tRunner", 0},
160 eventDesc{trace.EvGoStop, []frame{
161 frame{"runtime.block", 0},
162 frame{"runtime/trace_test.TestTraceSymbolize.func1", 38},
164 eventDesc{trace.EvGoStop, []frame{
165 frame{"runtime.chansend1", 0},
166 frame{"runtime/trace_test.TestTraceSymbolize.func2", 42},
168 eventDesc{trace.EvGoStop, []frame{
169 frame{"runtime.chanrecv1", 0},
170 frame{"runtime/trace_test.TestTraceSymbolize.func3", 46},
172 eventDesc{trace.EvGoBlockRecv, []frame{
173 frame{"runtime.chanrecv1", 0},
174 frame{"runtime/trace_test.TestTraceSymbolize.func4", 50},
176 eventDesc{trace.EvGoUnblock, []frame{
177 frame{"runtime.chansend1", 0},
178 frame{"runtime/trace_test.TestTraceSymbolize", 109},
179 frame{"testing.tRunner", 0},
181 eventDesc{trace.EvGoBlockSend, []frame{
182 frame{"runtime.chansend1", 0},
183 frame{"runtime/trace_test.TestTraceSymbolize.func5", 54},
185 eventDesc{trace.EvGoUnblock, []frame{
186 frame{"runtime.chanrecv1", 0},
187 frame{"runtime/trace_test.TestTraceSymbolize", 110},
188 frame{"testing.tRunner", 0},
190 eventDesc{trace.EvGoBlockSelect, []frame{
191 frame{"runtime.selectgo", 0},
192 frame{"runtime/trace_test.TestTraceSymbolize.func6", 59},
194 eventDesc{trace.EvGoUnblock, []frame{
195 frame{"runtime.selectgo", 0},
196 frame{"runtime/trace_test.TestTraceSymbolize", 111},
197 frame{"testing.tRunner", 0},
199 eventDesc{trace.EvGoBlockSync, []frame{
200 frame{"sync.(*Mutex).Lock", 0},
201 frame{"runtime/trace_test.TestTraceSymbolize.func7", 67},
203 eventDesc{trace.EvGoUnblock, []frame{
204 frame{"sync.(*Mutex).Unlock", 0},
205 frame{"runtime/trace_test.TestTraceSymbolize", 115},
206 frame{"testing.tRunner", 0},
208 eventDesc{trace.EvGoBlockSync, []frame{
209 frame{"sync.(*WaitGroup).Wait", 0},
210 frame{"runtime/trace_test.TestTraceSymbolize.func8", 73},
212 eventDesc{trace.EvGoUnblock, []frame{
213 frame{"sync.(*WaitGroup).Add", 0},
214 frame{"sync.(*WaitGroup).Done", 0},
215 frame{"runtime/trace_test.TestTraceSymbolize", 116},
216 frame{"testing.tRunner", 0},
218 eventDesc{trace.EvGoBlockCond, []frame{
219 frame{"sync.(*Cond).Wait", 0},
220 frame{"runtime/trace_test.TestTraceSymbolize.func9", 78},
222 eventDesc{trace.EvGoUnblock, []frame{
223 frame{"sync.(*Cond).Signal", 0},
224 frame{"runtime/trace_test.TestTraceSymbolize", 117},
225 frame{"testing.tRunner", 0},
227 eventDesc{trace.EvGoSleep, []frame{
228 frame{"time.Sleep", 0},
229 frame{"runtime/trace_test.TestTraceSymbolize", 108},
230 frame{"testing.tRunner", 0},
233 // Stacks for the following events are OS-dependent due to OS-specific code in net package.
234 if runtime.GOOS != "windows" && runtime.GOOS != "plan9" {
235 want = append(want, []eventDesc{
236 eventDesc{trace.EvGoBlockNet, []frame{
237 frame{"net.(*netFD).accept", 0},
238 frame{"net.(*TCPListener).AcceptTCP", 0},
239 frame{"net.(*TCPListener).Accept", 0},
240 frame{"runtime/trace_test.TestTraceSymbolize.func10", 86},
242 eventDesc{trace.EvGoSysCall, []frame{
243 frame{"syscall.read", 0},
244 frame{"syscall.Read", 0},
245 frame{"os.(*File).read", 0},
246 frame{"os.(*File).Read", 0},
247 frame{"runtime/trace_test.TestTraceSymbolize.func11", 101},
251 matched := make([]bool, len(want))
252 for _, ev := range events {
254 for i, w := range want {
255 if matched[i] || w.Type != ev.Type || len(w.Stk) != len(ev.Stk) {
259 for fi, f := range ev.Stk {
261 if wf.Fn != f.Fn || wf.Line != 0 && wf.Line != f.Line {
268 for i, m := range matched {
273 t.Errorf("did not match event %v at %v:%v", trace.EventDescriptions[w.Type].Name, w.Stk[0].Fn, w.Stk[0].Line)
274 t.Errorf("seen the following events of this type:")
275 for _, ev := range events {
276 if ev.Type != w.Type {
279 for _, f := range ev.Stk {
280 t.Logf(" %v:%v", f.Fn, f.Line)