Skip to content

Commit 45f4913

Browse files
prattmicprattmic
committed
runtime: test trap panic parsing in TestTracebackSystem
This mirrors https://go.dev/cl/637755, as x/telemetry is now aware of sigpanic preceding trap frames. For #70637. Change-Id: I13a775f25e89047702d4f2d463ce3210bcf192d9 Reviewed-on: https://go-review.googlesource.com/c/go/+/638015 Reviewed-by: Cherry Mui <[email protected]> LUCI-TryBot-Result: Go LUCI <[email protected]>
1 parent e63eb98 commit 45f4913

File tree

2 files changed

+202
-54
lines changed

2 files changed

+202
-54
lines changed

‎src/runtime/crash_test.go

+5-2
Original file line numberDiff line numberDiff line change
@@ -32,8 +32,11 @@ const entrypointVar = "RUNTIME_TEST_ENTRYPOINT"
3232

3333
func TestMain(m *testing.M) {
3434
switch entrypoint := os.Getenv(entrypointVar); entrypoint {
35-
case "crash":
36-
crash()
35+
case "panic":
36+
crashViaPanic()
37+
panic("unreachable")
38+
case "trap":
39+
crashViaTrap()
3740
panic("unreachable")
3841
default:
3942
log.Fatalf("invalid %s: %q", entrypointVar, entrypoint)

‎src/runtime/traceback_system_test.go

+197-52
Original file line numberDiff line numberDiff line change
@@ -23,8 +23,8 @@ import (
2323
)
2424

2525
// This is the entrypoint of the child process used by
26-
// TestTracebackSystem. It prints a crash report to stdout.
27-
func crash() {
26+
// TestTracebackSystem/panic. It prints a crash report to stdout.
27+
func crashViaPanic() {
2828
// Ensure that we get pc=0x%x values in the traceback.
2929
debug.SetTraceback("system")
3030
writeSentinel(os.Stdout)
@@ -37,6 +37,21 @@ func crash() {
3737
select {}
3838
}
3939

40+
// This is the entrypoint of the child process used by
41+
// TestTracebackSystem/trap. It prints a crash report to stdout.
42+
func crashViaTrap() {
43+
// Ensure that we get pc=0x%x values in the traceback.
44+
debug.SetTraceback("system")
45+
writeSentinel(os.Stdout)
46+
debug.SetCrashOutput(os.Stdout, debug.CrashOptions{})
47+
48+
go func() {
49+
// This call is typically inlined.
50+
trap1()
51+
}()
52+
select {}
53+
}
54+
4055
func child1() {
4156
child2()
4257
}
@@ -85,6 +100,20 @@ func child7() {
85100
panic("oops")
86101
}
87102

103+
func trap1() {
104+
trap2()
105+
}
106+
107+
var sinkPtr *int
108+
109+
func trap2() {
110+
trap3(sinkPtr)
111+
}
112+
113+
func trap3(i *int) {
114+
*i = 42
115+
}
116+
88117
// TestTracebackSystem tests that the syntax of crash reports produced
89118
// by GOTRACEBACK=system (see traceback2) contains a complete,
90119
// parseable list of program counters for the running goroutine that
@@ -100,46 +129,75 @@ func TestTracebackSystem(t *testing.T) {
100129
t.Skip("Can't read source code for this file on Android")
101130
}
102131

103-
// Fork+exec the crashing process.
104-
exe, err := os.Executable()
105-
if err != nil {
106-
t.Fatal(err)
107-
}
108-
cmd := testenv.Command(t, exe)
109-
cmd.Env = append(cmd.Environ(), entrypointVar+"=crash")
110-
var stdout, stderr bytes.Buffer
111-
cmd.Stdout = &stdout
112-
cmd.Stderr = &stderr
113-
cmd.Run() // expected to crash
114-
t.Logf("stderr:\n%s\nstdout: %s\n", stderr.Bytes(), stdout.Bytes())
115-
crash := stdout.String()
116-
117-
// If the only line is the sentinel, it wasn't a crash.
118-
if strings.Count(crash, "\n") < 2 {
119-
t.Fatalf("child process did not produce a crash report")
132+
tests := []struct{
133+
name string
134+
want string
135+
}{
136+
{
137+
name: "panic",
138+
want: `redacted.go:0: runtime.gopanic
139+
traceback_system_test.go:100: runtime_test.child7: panic("oops")
140+
traceback_system_test.go:83: runtime_test.child6: child7() // appears in stack trace
141+
traceback_system_test.go:74: runtime_test.child5: child6() // appears in stack trace
142+
traceback_system_test.go:68: runtime_test.child4: child5()
143+
traceback_system_test.go:64: runtime_test.child3: child4()
144+
traceback_system_test.go:60: runtime_test.child2: child3()
145+
traceback_system_test.go:56: runtime_test.child1: child2()
146+
traceback_system_test.go:35: runtime_test.crashViaPanic.func1: child1()
147+
redacted.go:0: runtime.goexit
148+
`,
149+
},
150+
{
151+
// Test panic via trap. x/telemetry is aware that trap
152+
// PCs follow runtime.sigpanic and need to be
153+
// incremented to offset the decrement done by
154+
// CallersFrames.
155+
name: "trap",
156+
want: `redacted.go:0: runtime.gopanic
157+
redacted.go:0: runtime.panicmem
158+
redacted.go:0: runtime.sigpanic
159+
traceback_system_test.go:114: runtime_test.trap3: *i = 42
160+
traceback_system_test.go:110: runtime_test.trap2: trap3(sinkPtr)
161+
traceback_system_test.go:104: runtime_test.trap1: trap2()
162+
traceback_system_test.go:50: runtime_test.crashViaTrap.func1: trap1()
163+
redacted.go:0: runtime.goexit
164+
`,
165+
},
120166
}
121167

122-
// Parse the PCs out of the child's crash report.
123-
pcs, err := parseStackPCs(crash)
124-
if err != nil {
125-
t.Fatal(err)
126-
}
168+
for _, tc := range tests {
169+
t.Run(tc.name, func(t *testing.T) {
170+
// Fork+exec the crashing process.
171+
exe, err := os.Executable()
172+
if err != nil {
173+
t.Fatal(err)
174+
}
175+
cmd := testenv.Command(t, exe)
176+
cmd.Env = append(cmd.Environ(), entrypointVar+"="+tc.name)
177+
var stdout, stderr bytes.Buffer
178+
cmd.Stdout = &stdout
179+
cmd.Stderr = &stderr
180+
cmd.Run() // expected to crash
181+
t.Logf("stderr:\n%s\nstdout: %s\n", stderr.Bytes(), stdout.Bytes())
182+
crash := stdout.String()
183+
184+
// If the only line is the sentinel, it wasn't a crash.
185+
if strings.Count(crash, "\n") < 2 {
186+
t.Fatalf("child process did not produce a crash report")
187+
}
127188

128-
// Unwind the stack using this executable's symbol table.
129-
got := formatStack(pcs)
130-
want := `redacted.go:0: runtime.gopanic
131-
traceback_system_test.go:85: runtime_test.child7: panic("oops")
132-
traceback_system_test.go:68: runtime_test.child6: child7() // appears in stack trace
133-
traceback_system_test.go:59: runtime_test.child5: child6() // appears in stack trace
134-
traceback_system_test.go:53: runtime_test.child4: child5()
135-
traceback_system_test.go:49: runtime_test.child3: child4()
136-
traceback_system_test.go:45: runtime_test.child2: child3()
137-
traceback_system_test.go:41: runtime_test.child1: child2()
138-
traceback_system_test.go:35: runtime_test.crash.func1: child1()
139-
redacted.go:0: runtime.goexit
140-
`
141-
if strings.TrimSpace(got) != strings.TrimSpace(want) {
142-
t.Errorf("got:\n%swant:\n%s", got, want)
189+
// Parse the PCs out of the child's crash report.
190+
pcs, err := parseStackPCs(crash)
191+
if err != nil {
192+
t.Fatal(err)
193+
}
194+
195+
// Unwind the stack using this executable's symbol table.
196+
got := formatStack(pcs)
197+
if strings.TrimSpace(got) != strings.TrimSpace(tc.want) {
198+
t.Errorf("got:\n%swant:\n%s", got, tc.want)
199+
}
200+
})
143201
}
144202
}
145203

@@ -154,6 +212,35 @@ redacted.go:0: runtime.goexit
154212
//
155213
// (Copied from golang.org/x/telemetry/crashmonitor.parseStackPCs.)
156214
func parseStackPCs(crash string) ([]uintptr, error) {
215+
// getSymbol parses the symbol name out of a line of the form:
216+
// SYMBOL(ARGS)
217+
//
218+
// Note: SYMBOL may contain parens "pkg.(*T).method". However, type
219+
// parameters are always replaced with ..., so they cannot introduce
220+
// more parens. e.g., "pkg.(*T[...]).method".
221+
//
222+
// ARGS can contain parens. We want the first paren that is not
223+
// immediately preceded by a ".".
224+
//
225+
// TODO(prattmic): This is mildly complicated and is only used to find
226+
// runtime.sigpanic, so perhaps simplify this by checking explicitly
227+
// for sigpanic.
228+
getSymbol := func(line string) (string, error) {
229+
var prev rune
230+
for i, c := range line {
231+
if line[i] != '(' {
232+
prev = c
233+
continue
234+
}
235+
if prev == '.' {
236+
prev = c
237+
continue
238+
}
239+
return line[:i], nil
240+
}
241+
return "", fmt.Errorf("no symbol for stack frame: %s", line)
242+
}
243+
157244
// getPC parses the PC out of a line of the form:
158245
// \tFILE:LINE +0xRELPC sp=... fp=... pc=...
159246
getPC := func(line string) (uint64, error) {
@@ -170,6 +257,9 @@ func parseStackPCs(crash string) ([]uintptr, error) {
170257
childSentinel = sentinel()
171258
on = false // are we in the first running goroutine?
172259
lines = strings.Split(crash, "\n")
260+
symLine = true // within a goroutine, every other line is a symbol or file/line/pc location, starting with symbol.
261+
currSymbol string
262+
prevSymbol string // symbol of the most recent previous frame with a PC.
173263
)
174264
for i := 0; i < len(lines); i++ {
175265
line := lines[i]
@@ -212,21 +302,76 @@ func parseStackPCs(crash string) ([]uintptr, error) {
212302
// Note: SYMBOL may contain parens "pkg.(*T).method"
213303
// The RELPC is sometimes missing.
214304

215-
// Skip the symbol(args) line.
216-
i++
217-
if i == len(lines) {
218-
break
219-
}
220-
line = lines[i]
305+
if symLine {
306+
var err error
307+
currSymbol, err = getSymbol(line)
308+
if err != nil {
309+
return nil, fmt.Errorf("error extracting symbol: %v", err)
310+
}
221311

222-
// Parse the PC, and correct for the parent and child's
223-
// different mappings of the text section.
224-
pc, err := getPC(line)
225-
if err != nil {
226-
// Inlined frame, perhaps; skip it.
227-
continue
312+
symLine = false // Next line is FILE:LINE.
313+
} else {
314+
// Parse the PC, and correct for the parent and child's
315+
// different mappings of the text section.
316+
pc, err := getPC(line)
317+
if err != nil {
318+
// Inlined frame, perhaps; skip it.
319+
320+
// Done with this frame. Next line is a new frame.
321+
//
322+
// Don't update prevSymbol; we only want to
323+
// track frames with a PC.
324+
currSymbol = ""
325+
symLine = true
326+
continue
327+
}
328+
329+
pc = pc-parentSentinel+childSentinel
330+
331+
// If the previous frame was sigpanic, then this frame
332+
// was a trap (e.g., SIGSEGV).
333+
//
334+
// Typically all middle frames are calls, and report
335+
// the "return PC". That is, the instruction following
336+
// the CALL where the callee will eventually return to.
337+
//
338+
// runtime.CallersFrames is aware of this property and
339+
// will decrement each PC by 1 to "back up" to the
340+
// location of the CALL, which is the actual line
341+
// number the user expects.
342+
//
343+
// This does not work for traps, as a trap is not a
344+
// call, so the reported PC is not the return PC, but
345+
// the actual PC of the trap.
346+
//
347+
// runtime.Callers is aware of this and will
348+
// intentionally increment trap PCs in order to correct
349+
// for the decrement performed by
350+
// runtime.CallersFrames. See runtime.tracebackPCs and
351+
// runtume.(*unwinder).symPC.
352+
//
353+
// We must emulate the same behavior, otherwise we will
354+
// report the location of the instruction immediately
355+
// prior to the trap, which may be on a different line,
356+
// or even a different inlined functions.
357+
//
358+
// TODO(prattmic): The runtime applies the same trap
359+
// behavior for other "injected calls", see injectCall
360+
// in runtime.(*unwinder).next. Do we want to handle
361+
// those as well? I don't believe we'd ever see
362+
// runtime.asyncPreempt or runtime.debugCallV2 in a
363+
// typical crash.
364+
if prevSymbol == "runtime.sigpanic" {
365+
pc++
366+
}
367+
368+
pcs = append(pcs, uintptr(pc))
369+
370+
// Done with this frame. Next line is a new frame.
371+
prevSymbol = currSymbol
372+
currSymbol = ""
373+
symLine = true
228374
}
229-
pcs = append(pcs, uintptr(pc-parentSentinel+childSentinel))
230375
}
231376
return pcs, nil
232377
}

0 commit comments

Comments
 (0)