From: Austin Clements Date: Mon, 6 Feb 2023 19:13:54 +0000 (-0500) Subject: runtime: add tests of printing inlined frames in tracebacks X-Git-Tag: go1.21rc1~1324 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=59d0de16e4f003e69403eeee969f0b4a96dd6dcb;p=gostls13.git runtime: add tests of printing inlined frames in tracebacks We're about to rewrite this code and it has almost no test coverage right now. This test is also more complete than the existing TestTracebackInlineExcluded, so we delete that test. For #54466. Change-Id: I144154282dac5eb3798f7d332b806f44c4a0bdf6 Reviewed-on: https://go-review.googlesource.com/c/go/+/466098 TryBot-Result: Gopher Robot Run-TryBot: Austin Clements Reviewed-by: Michael Pratt --- diff --git a/src/runtime/stack_test.go b/src/runtime/stack_test.go index 92d58803fc..24f8290f67 100644 --- a/src/runtime/stack_test.go +++ b/src/runtime/stack_test.go @@ -897,43 +897,3 @@ func deferHeapAndStack(n int) (r int) { // Pass a value to escapeMe to force it to escape. var escapeMe = func(x any) {} - -// Test that when F -> G is inlined and F is excluded from stack -// traces, G still appears. -func TestTracebackInlineExcluded(t *testing.T) { - defer func() { - recover() - buf := make([]byte, 4<<10) - stk := string(buf[:Stack(buf, false)]) - - t.Log(stk) - - if not := "tracebackExcluded"; strings.Contains(stk, not) { - t.Errorf("found but did not expect %q", not) - } - if want := "tracebackNotExcluded"; !strings.Contains(stk, want) { - t.Errorf("expected %q in stack", want) - } - }() - tracebackExcluded() -} - -// tracebackExcluded should be excluded from tracebacks. There are -// various ways this could come up. Linking it to a "runtime." name is -// rather synthetic, but it's easy and reliable. See issue #42754 for -// one way this happened in real code. -// -//go:linkname tracebackExcluded runtime.tracebackExcluded -//go:noinline -func tracebackExcluded() { - // Call an inlined function that should not itself be excluded - // from tracebacks. - tracebackNotExcluded() -} - -// tracebackNotExcluded should be inlined into tracebackExcluded, but -// should not itself be excluded from the traceback. -func tracebackNotExcluded() { - var x *int - *x = 0 -} diff --git a/src/runtime/traceback_test.go b/src/runtime/traceback_test.go index 8b19087b93..b0a383ae71 100644 --- a/src/runtime/traceback_test.go +++ b/src/runtime/traceback_test.go @@ -10,11 +10,143 @@ import ( "internal/abi" "internal/testenv" "runtime" + "runtime/debug" "strings" "sync" "testing" + _ "unsafe" ) +// Test traceback printing of inlined frames. +func TestTracebackInlined(t *testing.T) { + check := func(t *testing.T, r *ttiResult, funcs ...string) { + t.Helper() + + // Check the printed traceback. + frames := parseTraceback1(t, r.printed).frames + t.Log(r.printed) + // Find ttiLeaf + for len(frames) > 0 && frames[0].funcName != "runtime_test.ttiLeaf" { + frames = frames[1:] + } + if len(frames) == 0 { + t.Errorf("missing runtime_test.ttiLeaf") + return + } + frames = frames[1:] + // Check the function sequence. + for i, want := range funcs { + got := "" + if i < len(frames) { + got = frames[i].funcName + if strings.HasSuffix(want, ")") { + got += "(" + frames[i].args + ")" + } + } + if got != want { + t.Errorf("got %s, want %s", got, want) + return + } + } + } + + t.Run("simple", func(t *testing.T) { + // Check a simple case of inlining + r := ttiSimple1() + check(t, r, "runtime_test.ttiSimple3(...)", "runtime_test.ttiSimple2(...)", "runtime_test.ttiSimple1()") + }) + + t.Run("sigpanic", func(t *testing.T) { + // Check that sigpanic from an inlined function prints correctly + r := ttiSigpanic1() + check(t, r, "runtime_test.ttiSigpanic1.func1()", "panic", "runtime_test.ttiSigpanic3(...)", "runtime_test.ttiSigpanic2(...)", "runtime_test.ttiSigpanic1()") + }) + + t.Run("wrapper", func(t *testing.T) { + // Check that a method inlined into a wrapper prints correctly + r := ttiWrapper1() + check(t, r, "runtime_test.ttiWrapper.m1(...)", "runtime_test.ttiWrapper1()") + }) + + t.Run("excluded", func(t *testing.T) { + // Check that when F -> G is inlined and F is excluded from stack + // traces, G still appears. + r := ttiExcluded1() + check(t, r, "runtime_test.ttiExcluded3(...)", "runtime_test.ttiExcluded1()") + }) +} + +type ttiResult struct { + printed string +} + +//go:noinline +func ttiLeaf() *ttiResult { + // Get a printed stack trace. + printed := string(debug.Stack()) + return &ttiResult{printed} +} + +//go:noinline +func ttiSimple1() *ttiResult { + return ttiSimple2() +} +func ttiSimple2() *ttiResult { + return ttiSimple3() +} +func ttiSimple3() *ttiResult { + return ttiLeaf() +} + +//go:noinline +func ttiSigpanic1() (res *ttiResult) { + defer func() { + res = ttiLeaf() + recover() + }() + ttiSigpanic2() + panic("did not panic") +} +func ttiSigpanic2() { + ttiSigpanic3() +} +func ttiSigpanic3() { + var p *int + *p = 3 +} + +//go:noinline +func ttiWrapper1() *ttiResult { + var w ttiWrapper + m := (*ttiWrapper).m1 + return m(&w) +} + +type ttiWrapper struct{} + +func (w ttiWrapper) m1() *ttiResult { + return ttiLeaf() +} + +//go:noinline +func ttiExcluded1() *ttiResult { + return ttiExcluded2() +} + +// ttiExcluded2 should be excluded from tracebacks. There are +// various ways this could come up. Linking it to a "runtime." name is +// rather synthetic, but it's easy and reliable. See issue #42754 for +// one way this happened in real code. +// +//go:linkname ttiExcluded2 runtime.ttiExcluded2 +//go:noinline +func ttiExcluded2() *ttiResult { + return ttiExcluded3() +} +func ttiExcluded3() *ttiResult { + return ttiLeaf() +} + var testTracebackArgsBuf [1000]byte func TestTracebackArgs(t *testing.T) { @@ -443,3 +575,72 @@ func TestTracebackParentChildGoroutines(t *testing.T) { }() wg.Wait() } + +type traceback struct { + frames []*tbFrame + createdBy *tbFrame // no args +} + +type tbFrame struct { + funcName string + args string + inlined bool +} + +// parseTraceback parses a printed traceback to make it easier for tests to +// check the result. +func parseTraceback(t *testing.T, tb string) []*traceback { + lines := strings.Split(tb, "\n") + nLines := len(lines) + fatal := func(f string, args ...any) { + lineNo := nLines - len(lines) + 1 + msg := fmt.Sprintf(f, args...) + t.Fatalf("%s (line %d):\n%s", msg, lineNo, tb) + } + parseFrame := func(funcName, args string) *tbFrame { + // Consume file/line/etc + if len(lines) == 0 || !strings.HasPrefix(lines[0], "\t") { + fatal("missing source line") + } + lines = lines[1:] + inlined := args == "..." + return &tbFrame{funcName, args, inlined} + } + var tbs []*traceback + var cur *traceback + for len(lines) > 0 { + line := lines[0] + lines = lines[1:] + switch { + case strings.HasPrefix(line, "goroutine "): + cur = &traceback{} + tbs = append(tbs, cur) + case line == "": + cur = nil + case line[0] == '\t': + fatal("unexpected indent") + case strings.HasPrefix(line, "created by "): + funcName := line[len("created by "):] + cur.createdBy = parseFrame(funcName, "") + case strings.HasSuffix(line, ")"): + line = line[:len(line)-1] // Trim trailing ")" + funcName, args, found := strings.Cut(line, "(") + if !found { + fatal("missing (") + } + frame := parseFrame(funcName, args) + cur.frames = append(cur.frames, frame) + } + } + return tbs +} + +// parseTraceback1 is like parseTraceback, but expects tb to contain exactly one +// goroutine. +func parseTraceback1(t *testing.T, tb string) *traceback { + tbs := parseTraceback(t, tb) + if len(tbs) != 1 { + t.Fatalf("want 1 goroutine, got %d:\n%s", len(tbs), tb) + } + return tbs[0] +}