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.Errorf("failed to accept: %v", err)
93 rp, wp, err := os.Pipe()
95 t.Fatalf("failed to create a pipe: %v", err)
99 pipeReadDone := make(chan bool)
106 time.Sleep(100 * time.Millisecond)
109 time.Sleep(100 * time.Millisecond) // the last chance for the goroutines above to block
119 c, err := net.Dial("tcp", ln.Addr().String())
121 t.Fatalf("failed to dial: %v", err)
129 events, _ := parseTrace(t, buf)
131 // Now check that the stacks are correct.
136 type eventDesc struct {
141 {trace.EvGCStart, []frame{
143 {"runtime/trace_test.TestTraceSymbolize", 107},
144 {"testing.tRunner", 0},
146 {trace.EvGoStart, []frame{
147 {"runtime/trace_test.TestTraceSymbolize.func1", 37},
149 {trace.EvGoSched, []frame{
150 {"runtime/trace_test.TestTraceSymbolize", 108},
151 {"testing.tRunner", 0},
153 {trace.EvGoCreate, []frame{
154 {"runtime/trace_test.TestTraceSymbolize", 37},
155 {"testing.tRunner", 0},
157 {trace.EvGoStop, []frame{
158 {"runtime.block", 0},
159 {"runtime/trace_test.TestTraceSymbolize.func1", 38},
161 {trace.EvGoStop, []frame{
162 {"runtime.chansend1", 0},
163 {"runtime/trace_test.TestTraceSymbolize.func2", 42},
165 {trace.EvGoStop, []frame{
166 {"runtime.chanrecv1", 0},
167 {"runtime/trace_test.TestTraceSymbolize.func3", 46},
169 {trace.EvGoBlockRecv, []frame{
170 {"runtime.chanrecv1", 0},
171 {"runtime/trace_test.TestTraceSymbolize.func4", 50},
173 {trace.EvGoUnblock, []frame{
174 {"runtime.chansend1", 0},
175 {"runtime/trace_test.TestTraceSymbolize", 110},
176 {"testing.tRunner", 0},
178 {trace.EvGoBlockSend, []frame{
179 {"runtime.chansend1", 0},
180 {"runtime/trace_test.TestTraceSymbolize.func5", 54},
182 {trace.EvGoUnblock, []frame{
183 {"runtime.chanrecv1", 0},
184 {"runtime/trace_test.TestTraceSymbolize", 111},
185 {"testing.tRunner", 0},
187 {trace.EvGoBlockSelect, []frame{
188 {"runtime.selectgo", 0},
189 {"runtime/trace_test.TestTraceSymbolize.func6", 59},
191 {trace.EvGoUnblock, []frame{
192 {"runtime.selectgo", 0},
193 {"runtime/trace_test.TestTraceSymbolize", 112},
194 {"testing.tRunner", 0},
196 {trace.EvGoBlockSync, []frame{
197 {"sync.(*Mutex).Lock", 0},
198 {"runtime/trace_test.TestTraceSymbolize.func7", 67},
200 {trace.EvGoUnblock, []frame{
201 {"sync.(*Mutex).Unlock", 0},
202 {"runtime/trace_test.TestTraceSymbolize", 116},
203 {"testing.tRunner", 0},
205 {trace.EvGoBlockSync, []frame{
206 {"sync.(*WaitGroup).Wait", 0},
207 {"runtime/trace_test.TestTraceSymbolize.func8", 73},
209 {trace.EvGoUnblock, []frame{
210 {"sync.(*WaitGroup).Add", 0},
211 {"sync.(*WaitGroup).Done", 0},
212 {"runtime/trace_test.TestTraceSymbolize", 117},
213 {"testing.tRunner", 0},
215 {trace.EvGoBlockCond, []frame{
216 {"sync.(*Cond).Wait", 0},
217 {"runtime/trace_test.TestTraceSymbolize.func9", 78},
219 {trace.EvGoUnblock, []frame{
220 {"sync.(*Cond).Signal", 0},
221 {"runtime/trace_test.TestTraceSymbolize", 118},
222 {"testing.tRunner", 0},
224 {trace.EvGoSleep, []frame{
226 {"runtime/trace_test.TestTraceSymbolize", 109},
227 {"testing.tRunner", 0},
230 // Stacks for the following events are OS-dependent due to OS-specific code in net package.
231 if runtime.GOOS != "windows" && runtime.GOOS != "plan9" {
232 want = append(want, []eventDesc{
233 {trace.EvGoBlockNet, []frame{
234 {"internal/poll.(*FD).Accept", 0},
235 {"net.(*netFD).accept", 0},
236 {"net.(*TCPListener).accept", 0},
237 {"net.(*TCPListener).Accept", 0},
238 {"runtime/trace_test.TestTraceSymbolize.func10", 86},
240 {trace.EvGoSysCall, []frame{
243 {"internal/poll.(*FD).Read", 0},
244 {"os.(*File).read", 0},
245 {"os.(*File).Read", 0},
246 {"runtime/trace_test.TestTraceSymbolize.func11", 102},
250 matched := make([]bool, len(want))
251 for _, ev := range events {
253 for i, w := range want {
254 if matched[i] || w.Type != ev.Type || len(w.Stk) != len(ev.Stk) {
258 for fi, f := range ev.Stk {
260 if wf.Fn != f.Fn || wf.Line != 0 && wf.Line != f.Line {
267 for i, m := range matched {
272 t.Errorf("did not match event %v at %v:%v", trace.EventDescriptions[w.Type].Name, w.Stk[0].Fn, w.Stk[0].Line)
273 t.Errorf("seen the following events of this type:")
274 for _, ev := range events {
275 if ev.Type != w.Type {
278 for _, f := range ev.Stk {
279 t.Logf(" %v :: %s:%v", f.Fn, f.File, f.Line)