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.MustHaveGoBuild(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 {trace.EvGCStart, []frame{
149 {"runtime/trace_test.TestTraceSymbolize", 106},
150 {"testing.tRunner", 0},
152 {trace.EvGoSched, []frame{
153 {"runtime/trace_test.TestTraceSymbolize", 107},
154 {"testing.tRunner", 0},
156 {trace.EvGoCreate, []frame{
157 {"runtime/trace_test.TestTraceSymbolize", 39},
158 {"testing.tRunner", 0},
160 {trace.EvGoStop, []frame{
161 {"runtime.block", 0},
162 {"runtime/trace_test.TestTraceSymbolize.func1", 38},
164 {trace.EvGoStop, []frame{
165 {"runtime.chansend1", 0},
166 {"runtime/trace_test.TestTraceSymbolize.func2", 42},
168 {trace.EvGoStop, []frame{
169 {"runtime.chanrecv1", 0},
170 {"runtime/trace_test.TestTraceSymbolize.func3", 46},
172 {trace.EvGoBlockRecv, []frame{
173 {"runtime.chanrecv1", 0},
174 {"runtime/trace_test.TestTraceSymbolize.func4", 50},
176 {trace.EvGoUnblock, []frame{
177 {"runtime.chansend1", 0},
178 {"runtime/trace_test.TestTraceSymbolize", 109},
179 {"testing.tRunner", 0},
181 {trace.EvGoBlockSend, []frame{
182 {"runtime.chansend1", 0},
183 {"runtime/trace_test.TestTraceSymbolize.func5", 54},
185 {trace.EvGoUnblock, []frame{
186 {"runtime.chanrecv1", 0},
187 {"runtime/trace_test.TestTraceSymbolize", 110},
188 {"testing.tRunner", 0},
190 {trace.EvGoBlockSelect, []frame{
191 {"runtime.selectgo", 0},
192 {"runtime/trace_test.TestTraceSymbolize.func6", 59},
194 {trace.EvGoUnblock, []frame{
195 {"runtime.selectgo", 0},
196 {"runtime/trace_test.TestTraceSymbolize", 111},
197 {"testing.tRunner", 0},
199 {trace.EvGoBlockSync, []frame{
200 {"sync.(*Mutex).Lock", 0},
201 {"runtime/trace_test.TestTraceSymbolize.func7", 67},
203 {trace.EvGoUnblock, []frame{
204 {"sync.(*Mutex).Unlock", 0},
205 {"runtime/trace_test.TestTraceSymbolize", 115},
206 {"testing.tRunner", 0},
208 {trace.EvGoBlockSync, []frame{
209 {"sync.(*WaitGroup).Wait", 0},
210 {"runtime/trace_test.TestTraceSymbolize.func8", 73},
212 {trace.EvGoUnblock, []frame{
213 {"sync.(*WaitGroup).Add", 0},
214 {"sync.(*WaitGroup).Done", 0},
215 {"runtime/trace_test.TestTraceSymbolize", 116},
216 {"testing.tRunner", 0},
218 {trace.EvGoBlockCond, []frame{
219 {"sync.(*Cond).Wait", 0},
220 {"runtime/trace_test.TestTraceSymbolize.func9", 78},
222 {trace.EvGoUnblock, []frame{
223 {"sync.(*Cond).Signal", 0},
224 {"runtime/trace_test.TestTraceSymbolize", 117},
225 {"testing.tRunner", 0},
227 {trace.EvGoSleep, []frame{
229 {"runtime/trace_test.TestTraceSymbolize", 108},
230 {"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 {trace.EvGoBlockNet, []frame{
237 {"net.(*netFD).accept", 0},
238 {"net.(*TCPListener).AcceptTCP", 0},
239 {"net.(*TCPListener).Accept", 0},
240 {"runtime/trace_test.TestTraceSymbolize.func10", 86},
242 {trace.EvGoSysCall, []frame{
245 {"os.(*File).read", 0},
246 {"os.(*File).Read", 0},
247 {"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)