go/src/runtime/crash_test.go

806 lines
21 KiB
Go
Raw Normal View History

// Copyright 2012 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package runtime_test
import (
"bytes"
"flag"
"fmt"
"internal/testenv"
"os"
"os/exec"
"path/filepath"
"regexp"
"runtime"
"strconv"
"strings"
"sync"
"testing"
"time"
)
var toRemove []string
func TestMain(m *testing.M) {
status := m.Run()
for _, file := range toRemove {
os.RemoveAll(file)
}
os.Exit(status)
}
var testprog struct {
sync.Mutex
dir string
target map[string]buildexe
}
type buildexe struct {
exe string
err error
}
func runTestProg(t *testing.T, binary, name string, env ...string) string {
if *flagQuick {
t.Skip("-quick")
}
testenv.MustHaveGoBuild(t)
exe, err := buildTestProg(t, binary)
if err != nil {
t.Fatal(err)
}
runtime: disable preemption in startTemplateThread When a locked M wants to start a new M, it hands off to the template thread to actually call clone and start the thread. The template thread is lazily created the first time a thread is locked (or if cgo is in use). stoplockedm will release the P (_Pidle), then call handoffp to give the P to another M. In the case of a pending STW, one of two things can happen: 1. handoffp starts an M, which does acquirep followed by schedule, which will finally enter _Pgcstop. 2. handoffp immediately enters _Pgcstop. This only occurs if the P has no local work, GC work, and no spinning M is required. If handoffp starts an M, and must create a new M to do so, then newm will simply queue the M on newmHandoff for the template thread to do the clone. When a stop-the-world is required, stopTheWorldWithSema will start the stop and then wait for all Ps to enter _Pgcstop. If the template thread is not fully created because startTemplateThread gets stopped, then another stoplockedm may queue an M that will never get created, and the handoff P will never leave _Pidle. Thus stopTheWorldWithSema will wait forever. A sequence to trigger this hang when STW occurs can be visualized with two threads: T1 T2 ------------------------------- ----------------------------- LockOSThread LockOSThread haveTemplateThread == 0 startTemplateThread haveTemplateThread = 1 newm haveTemplateThread == 1 preempt -> schedule g.m.lockedExt++ gcstopm -> _Pgcstop g.m.lockedg = ... park g.lockedm = ... return ... (any code) preempt -> schedule stoplockedm releasep -> _Pidle handoffp startm (first 3 handoffp cases) newm g.m.lockedExt != 0 Add to newmHandoff, return park Note that the P in T2 is stuck sitting in _Pidle. Since the template thread isn't running, the new M will not be started complete the transition to _Pgcstop. To resolve this, we disable preemption around the assignment of haveTemplateThread and the creation of the template thread in order to guarantee that if handTemplateThread is set then the template thread will eventually exist, in the presence of stops. Fixes #38931 Change-Id: I50535fbbe2f328f47b18e24d9030136719274191 Reviewed-on: https://go-review.googlesource.com/c/go/+/232978 Run-TryBot: Michael Pratt <mpratt@google.com> Reviewed-by: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2020-05-07 18:13:21 -04:00
return runBuiltTestProg(t, exe, name, env...)
}
func runBuiltTestProg(t *testing.T, exe, name string, env ...string) string {
if *flagQuick {
t.Skip("-quick")
}
testenv.MustHaveGoBuild(t)
cmd := testenv.CleanCmdEnv(exec.Command(exe, name))
cmd.Env = append(cmd.Env, env...)
if testing.Short() {
cmd.Env = append(cmd.Env, "RUNTIME_TEST_SHORT=1")
}
var b bytes.Buffer
cmd.Stdout = &b
cmd.Stderr = &b
if err := cmd.Start(); err != nil {
runtime: disable preemption in startTemplateThread When a locked M wants to start a new M, it hands off to the template thread to actually call clone and start the thread. The template thread is lazily created the first time a thread is locked (or if cgo is in use). stoplockedm will release the P (_Pidle), then call handoffp to give the P to another M. In the case of a pending STW, one of two things can happen: 1. handoffp starts an M, which does acquirep followed by schedule, which will finally enter _Pgcstop. 2. handoffp immediately enters _Pgcstop. This only occurs if the P has no local work, GC work, and no spinning M is required. If handoffp starts an M, and must create a new M to do so, then newm will simply queue the M on newmHandoff for the template thread to do the clone. When a stop-the-world is required, stopTheWorldWithSema will start the stop and then wait for all Ps to enter _Pgcstop. If the template thread is not fully created because startTemplateThread gets stopped, then another stoplockedm may queue an M that will never get created, and the handoff P will never leave _Pidle. Thus stopTheWorldWithSema will wait forever. A sequence to trigger this hang when STW occurs can be visualized with two threads: T1 T2 ------------------------------- ----------------------------- LockOSThread LockOSThread haveTemplateThread == 0 startTemplateThread haveTemplateThread = 1 newm haveTemplateThread == 1 preempt -> schedule g.m.lockedExt++ gcstopm -> _Pgcstop g.m.lockedg = ... park g.lockedm = ... return ... (any code) preempt -> schedule stoplockedm releasep -> _Pidle handoffp startm (first 3 handoffp cases) newm g.m.lockedExt != 0 Add to newmHandoff, return park Note that the P in T2 is stuck sitting in _Pidle. Since the template thread isn't running, the new M will not be started complete the transition to _Pgcstop. To resolve this, we disable preemption around the assignment of haveTemplateThread and the creation of the template thread in order to guarantee that if handTemplateThread is set then the template thread will eventually exist, in the presence of stops. Fixes #38931 Change-Id: I50535fbbe2f328f47b18e24d9030136719274191 Reviewed-on: https://go-review.googlesource.com/c/go/+/232978 Run-TryBot: Michael Pratt <mpratt@google.com> Reviewed-by: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2020-05-07 18:13:21 -04:00
t.Fatalf("starting %s %s: %v", exe, name, err)
}
// If the process doesn't complete within 1 minute,
// assume it is hanging and kill it to get a stack trace.
p := cmd.Process
done := make(chan bool)
go func() {
scale := 1
// This GOARCH/GOOS test is copied from cmd/dist/test.go.
// TODO(iant): Have cmd/dist update the environment variable.
if runtime.GOARCH == "arm" || runtime.GOOS == "windows" {
scale = 2
}
if s := os.Getenv("GO_TEST_TIMEOUT_SCALE"); s != "" {
if sc, err := strconv.Atoi(s); err == nil {
scale = sc
}
}
select {
case <-done:
case <-time.After(time.Duration(scale) * time.Minute):
p.Signal(sigquit)
}
}()
if err := cmd.Wait(); err != nil {
runtime: disable preemption in startTemplateThread When a locked M wants to start a new M, it hands off to the template thread to actually call clone and start the thread. The template thread is lazily created the first time a thread is locked (or if cgo is in use). stoplockedm will release the P (_Pidle), then call handoffp to give the P to another M. In the case of a pending STW, one of two things can happen: 1. handoffp starts an M, which does acquirep followed by schedule, which will finally enter _Pgcstop. 2. handoffp immediately enters _Pgcstop. This only occurs if the P has no local work, GC work, and no spinning M is required. If handoffp starts an M, and must create a new M to do so, then newm will simply queue the M on newmHandoff for the template thread to do the clone. When a stop-the-world is required, stopTheWorldWithSema will start the stop and then wait for all Ps to enter _Pgcstop. If the template thread is not fully created because startTemplateThread gets stopped, then another stoplockedm may queue an M that will never get created, and the handoff P will never leave _Pidle. Thus stopTheWorldWithSema will wait forever. A sequence to trigger this hang when STW occurs can be visualized with two threads: T1 T2 ------------------------------- ----------------------------- LockOSThread LockOSThread haveTemplateThread == 0 startTemplateThread haveTemplateThread = 1 newm haveTemplateThread == 1 preempt -> schedule g.m.lockedExt++ gcstopm -> _Pgcstop g.m.lockedg = ... park g.lockedm = ... return ... (any code) preempt -> schedule stoplockedm releasep -> _Pidle handoffp startm (first 3 handoffp cases) newm g.m.lockedExt != 0 Add to newmHandoff, return park Note that the P in T2 is stuck sitting in _Pidle. Since the template thread isn't running, the new M will not be started complete the transition to _Pgcstop. To resolve this, we disable preemption around the assignment of haveTemplateThread and the creation of the template thread in order to guarantee that if handTemplateThread is set then the template thread will eventually exist, in the presence of stops. Fixes #38931 Change-Id: I50535fbbe2f328f47b18e24d9030136719274191 Reviewed-on: https://go-review.googlesource.com/c/go/+/232978 Run-TryBot: Michael Pratt <mpratt@google.com> Reviewed-by: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org>
2020-05-07 18:13:21 -04:00
t.Logf("%s %s exit status: %v", exe, name, err)
}
close(done)
return b.String()
}
func buildTestProg(t *testing.T, binary string, flags ...string) (string, error) {
if *flagQuick {
t.Skip("-quick")
}
testprog.Lock()
defer testprog.Unlock()
if testprog.dir == "" {
dir, err := os.MkdirTemp("", "go-build")
if err != nil {
t.Fatalf("failed to create temp directory: %v", err)
}
testprog.dir = dir
toRemove = append(toRemove, dir)
}
if testprog.target == nil {
testprog.target = make(map[string]buildexe)
}
name := binary
if len(flags) > 0 {
name += "_" + strings.Join(flags, "_")
}
target, ok := testprog.target[name]
if ok {
return target.exe, target.err
}
exe := filepath.Join(testprog.dir, name+".exe")
cmd := exec.Command(testenv.GoToolPath(t), append([]string{"build", "-o", exe}, flags...)...)
cmd.Dir = "testdata/" + binary
out, err := testenv.CleanCmdEnv(cmd).CombinedOutput()
if err != nil {
target.err = fmt.Errorf("building %s %v: %v\n%s", binary, flags, err, out)
testprog.target[name] = target
return "", target.err
}
target.exe = exe
testprog.target[name] = target
return exe, nil
}
func TestVDSO(t *testing.T) {
t.Parallel()
output := runTestProg(t, "testprog", "SignalInVDSO")
want := "success\n"
if output != want {
t.Fatalf("output:\n%s\n\nwanted:\n%s", output, want)
}
}
func testCrashHandler(t *testing.T, cgo bool) {
type crashTest struct {
Cgo bool
}
var output string
if cgo {
output = runTestProg(t, "testprogcgo", "Crash")
} else {
output = runTestProg(t, "testprog", "Crash")
}
want := "main: recovered done\nnew-thread: recovered done\nsecond-new-thread: recovered done\nmain-again: recovered done\n"
if output != want {
t.Fatalf("output:\n%s\n\nwanted:\n%s", output, want)
}
}
func TestCrashHandler(t *testing.T) {
testCrashHandler(t, false)
}
func testDeadlock(t *testing.T, name string) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
output := runTestProg(t, "testprog", name)
want := "fatal error: all goroutines are asleep - deadlock!\n"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestSimpleDeadlock(t *testing.T) {
testDeadlock(t, "SimpleDeadlock")
}
func TestInitDeadlock(t *testing.T) {
testDeadlock(t, "InitDeadlock")
}
func TestLockedDeadlock(t *testing.T) {
testDeadlock(t, "LockedDeadlock")
}
func TestLockedDeadlock2(t *testing.T) {
testDeadlock(t, "LockedDeadlock2")
}
func TestGoexitDeadlock(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
output := runTestProg(t, "testprog", "GoexitDeadlock")
want := "no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.Contains(output, want) {
t.Fatalf("output:\n%s\n\nwant output containing: %s", output, want)
}
}
func TestStackOverflow(t *testing.T) {
output := runTestProg(t, "testprog", "StackOverflow")
want := []string{
"runtime: goroutine stack exceeds 1474560-byte limit\n",
"fatal error: stack overflow",
// information about the current SP and stack bounds
"runtime: sp=",
"stack=[",
}
if !strings.HasPrefix(output, want[0]) {
t.Errorf("output does not start with %q", want[0])
}
for _, s := range want[1:] {
if !strings.Contains(output, s) {
t.Errorf("output does not contain %q", s)
}
}
if t.Failed() {
t.Logf("output:\n%s", output)
}
}
func TestThreadExhaustion(t *testing.T) {
output := runTestProg(t, "testprog", "ThreadExhaustion")
want := "runtime: program exceeds 10-thread limit\nfatal error: thread exhaustion"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecursivePanic(t *testing.T) {
output := runTestProg(t, "testprog", "RecursivePanic")
want := `wrap: bad
panic: again
`
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecursivePanic2(t *testing.T) {
output := runTestProg(t, "testprog", "RecursivePanic2")
want := `first panic
second panic
panic: third panic
`
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecursivePanic3(t *testing.T) {
output := runTestProg(t, "testprog", "RecursivePanic3")
want := `panic: first panic
`
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
runtime: ensure that Goexit cannot be aborted by a recursive panic/recover When we do a successful recover of a panic, we resume normal execution by returning from the frame that had the deferred call that did the recover (after executing any remaining deferred calls in that frame). However, suppose we have called runtime.Goexit and there is a panic during one of the deferred calls run by the Goexit. Further assume that there is a deferred call in the frame of the Goexit or a parent frame that does a recover. Then the recovery process will actually resume normal execution above the Goexit frame and hence abort the Goexit. We will not terminate the thread as expected, but continue running in the frame above the Goexit. To fix this, we explicitly create a _panic object for a Goexit call. We then change the "abort" behavior for Goexits, but not panics. After a recovery, if the top-level panic is actually a Goexit that is marked to be aborted, then we return to the Goexit defer-processing loop, so that the Goexit is not actually aborted. Actual code changes are just panic.go, runtime2.go, and funcid.go. Adjusted the test related to the new Goexit behavior (TestRecoverBeforePanicAfterGoexit) and added several new tests of aborted panics (whose behavior has not changed). Fixes #29226 Change-Id: Ib13cb0074f5acc2567a28db7ca6912cfc47eecb5 Reviewed-on: https://go-review.googlesource.com/c/go/+/200081 Run-TryBot: Dan Scales <danscales@google.com> Reviewed-by: Keith Randall <khr@golang.org>
2019-10-09 12:18:26 -07:00
func TestRecursivePanic4(t *testing.T) {
output := runTestProg(t, "testprog", "RecursivePanic4")
want := `panic: first panic [recovered]
panic: second panic
`
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestGoexitCrash(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
output := runTestProg(t, "testprog", "GoexitExit")
want := "no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.Contains(output, want) {
t.Fatalf("output:\n%s\n\nwant output containing: %s", output, want)
}
}
func TestGoexitDefer(t *testing.T) {
c := make(chan struct{})
go func() {
defer func() {
r := recover()
if r != nil {
t.Errorf("non-nil recover during Goexit")
}
c <- struct{}{}
}()
runtime.Goexit()
}()
// Note: if the defer fails to run, we will get a deadlock here
<-c
}
func TestGoNil(t *testing.T) {
output := runTestProg(t, "testprog", "GoNil")
want := "go of nil func value"
if !strings.Contains(output, want) {
t.Fatalf("output:\n%s\n\nwant output containing: %s", output, want)
}
}
func TestMainGoroutineID(t *testing.T) {
output := runTestProg(t, "testprog", "MainGoroutineID")
want := "panic: test\n\ngoroutine 1 [running]:\n"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestNoHelperGoroutines(t *testing.T) {
output := runTestProg(t, "testprog", "NoHelperGoroutines")
matches := regexp.MustCompile(`goroutine [0-9]+ \[`).FindAllStringSubmatch(output, -1)
if len(matches) != 1 || matches[0][0] != "goroutine 1 [" {
t.Fatalf("want to see only goroutine 1, see:\n%s", output)
}
}
func TestBreakpoint(t *testing.T) {
output := runTestProg(t, "testprog", "Breakpoint")
// If runtime.Breakpoint() is inlined, then the stack trace prints
// "runtime.Breakpoint(...)" instead of "runtime.Breakpoint()".
want := "runtime.Breakpoint("
if !strings.Contains(output, want) {
t.Fatalf("output:\n%s\n\nwant output containing: %s", output, want)
}
}
func TestGoexitInPanic(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
// see issue 8774: this code used to trigger an infinite recursion
output := runTestProg(t, "testprog", "GoexitInPanic")
want := "fatal error: no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
// Issue 14965: Runtime panics should be of type runtime.Error
func TestRuntimePanicWithRuntimeError(t *testing.T) {
testCases := [...]func(){
0: func() {
var m map[uint64]bool
m[1234] = true
},
1: func() {
ch := make(chan struct{})
close(ch)
close(ch)
},
2: func() {
var ch = make(chan struct{})
close(ch)
ch <- struct{}{}
},
3: func() {
var s = make([]int, 2)
_ = s[2]
},
4: func() {
n := -1
_ = make(chan bool, n)
},
5: func() {
close((chan bool)(nil))
},
}
for i, fn := range testCases {
got := panicValue(fn)
if _, ok := got.(runtime.Error); !ok {
t.Errorf("test #%d: recovered value %v(type %T) does not implement runtime.Error", i, got, got)
}
}
}
func panicValue(fn func()) (recovered interface{}) {
defer func() {
recovered = recover()
}()
fn()
return
}
func TestPanicAfterGoexit(t *testing.T) {
// an uncaught panic should still work after goexit
output := runTestProg(t, "testprog", "PanicAfterGoexit")
want := "panic: hello"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecoveredPanicAfterGoexit(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
output := runTestProg(t, "testprog", "RecoveredPanicAfterGoexit")
want := "fatal error: no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecoverBeforePanicAfterGoexit(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
runtime: ensure that Goexit cannot be aborted by a recursive panic/recover When we do a successful recover of a panic, we resume normal execution by returning from the frame that had the deferred call that did the recover (after executing any remaining deferred calls in that frame). However, suppose we have called runtime.Goexit and there is a panic during one of the deferred calls run by the Goexit. Further assume that there is a deferred call in the frame of the Goexit or a parent frame that does a recover. Then the recovery process will actually resume normal execution above the Goexit frame and hence abort the Goexit. We will not terminate the thread as expected, but continue running in the frame above the Goexit. To fix this, we explicitly create a _panic object for a Goexit call. We then change the "abort" behavior for Goexits, but not panics. After a recovery, if the top-level panic is actually a Goexit that is marked to be aborted, then we return to the Goexit defer-processing loop, so that the Goexit is not actually aborted. Actual code changes are just panic.go, runtime2.go, and funcid.go. Adjusted the test related to the new Goexit behavior (TestRecoverBeforePanicAfterGoexit) and added several new tests of aborted panics (whose behavior has not changed). Fixes #29226 Change-Id: Ib13cb0074f5acc2567a28db7ca6912cfc47eecb5 Reviewed-on: https://go-review.googlesource.com/c/go/+/200081 Run-TryBot: Dan Scales <danscales@google.com> Reviewed-by: Keith Randall <khr@golang.org>
2019-10-09 12:18:26 -07:00
t.Parallel()
output := runTestProg(t, "testprog", "RecoverBeforePanicAfterGoexit")
want := "fatal error: no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestRecoverBeforePanicAfterGoexit2(t *testing.T) {
// External linking brings in cgo, causing deadlock detection not working.
testenv.MustInternalLink(t)
runtime: ensure that Goexit cannot be aborted by a recursive panic/recover When we do a successful recover of a panic, we resume normal execution by returning from the frame that had the deferred call that did the recover (after executing any remaining deferred calls in that frame). However, suppose we have called runtime.Goexit and there is a panic during one of the deferred calls run by the Goexit. Further assume that there is a deferred call in the frame of the Goexit or a parent frame that does a recover. Then the recovery process will actually resume normal execution above the Goexit frame and hence abort the Goexit. We will not terminate the thread as expected, but continue running in the frame above the Goexit. To fix this, we explicitly create a _panic object for a Goexit call. We then change the "abort" behavior for Goexits, but not panics. After a recovery, if the top-level panic is actually a Goexit that is marked to be aborted, then we return to the Goexit defer-processing loop, so that the Goexit is not actually aborted. Actual code changes are just panic.go, runtime2.go, and funcid.go. Adjusted the test related to the new Goexit behavior (TestRecoverBeforePanicAfterGoexit) and added several new tests of aborted panics (whose behavior has not changed). Fixes #29226 Change-Id: Ib13cb0074f5acc2567a28db7ca6912cfc47eecb5 Reviewed-on: https://go-review.googlesource.com/c/go/+/200081 Run-TryBot: Dan Scales <danscales@google.com> Reviewed-by: Keith Randall <khr@golang.org>
2019-10-09 12:18:26 -07:00
t.Parallel()
output := runTestProg(t, "testprog", "RecoverBeforePanicAfterGoexit2")
want := "fatal error: no goroutines (main called runtime.Goexit) - deadlock!"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestNetpollDeadlock(t *testing.T) {
if os.Getenv("GO_BUILDER_NAME") == "darwin-amd64-10_12" {
// A suspected kernel bug in macOS 10.12 occasionally results in
// an apparent deadlock when dialing localhost. The errors have not
// been observed on newer versions of the OS, so we don't plan to work
// around them. See https://golang.org/issue/22019.
testenv.SkipFlaky(t, 22019)
}
t.Parallel()
output := runTestProg(t, "testprognet", "NetpollDeadlock")
want := "done\n"
if !strings.HasSuffix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestPanicTraceback(t *testing.T) {
t.Parallel()
output := runTestProg(t, "testprog", "PanicTraceback")
want := "panic: hello\n\tpanic: panic pt2\n\tpanic: panic pt1\n"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
// Check functions in the traceback.
runtime: do not print runtime panic frame at top of user stack The expected default behavior (no explicit GOTRACEBACK setting) is for the stack trace to start in user code, eliding unnecessary runtime frames that led up to the actual trace printing code. The idea was that the first line number printed was the one that crashed. For #5832 we added code to show 'panic' frames so that if code panics and then starts running defers and then we trace from there, the panic frame can help explain why the code seems to have made a call not present in the code. But that's only needed for panics between two different call frames, not the panic at the very top of the stack trace. Fix the fix to again elide the runtime code at the very top of the stack trace. Simple panic: package main func main() { var x []int println(x[1]) } Before this CL: panic: runtime error: index out of range goroutine 1 [running]: panic(0x1056980, 0x1091bf0) /Users/rsc/go/src/runtime/panic.go:531 +0x1cf main.main() /tmp/x.go:5 +0x5 After this CL: panic: runtime error: index out of range goroutine 1 [running]: main.main() /tmp/x.go:5 +0x5 Panic inside defer triggered by panic: package main func main() { var x []int defer func() { println(x[1]) }() println(x[2]) } Before this CL: panic: runtime error: index out of range panic: runtime error: index out of range goroutine 1 [running]: panic(0x1056aa0, 0x1091bf0) /Users/rsc/go/src/runtime/panic.go:531 +0x1cf main.main.func1(0x0, 0x0, 0x0) /tmp/y.go:6 +0x62 panic(0x1056aa0, 0x1091bf0) /Users/rsc/go/src/runtime/panic.go:489 +0x2cf main.main() /tmp/y.go:8 +0x59 The middle panic is important: it explains why main.main ended up calling main.main.func1 on a line that looks like a call to println. The top panic is noise. After this CL: panic: runtime error: index out of range panic: runtime error: index out of range goroutine 1 [running]: main.main.func1(0x0, 0x0, 0x0) /tmp/y.go:6 +0x62 panic(0x1056ac0, 0x1091bf0) /Users/rsc/go/src/runtime/panic.go:489 +0x2cf main.main() /tmp/y.go:8 +0x59 Fixes #17901. Change-Id: Id6d7c76373f7a658a537a39ca32b7dc23e1e76aa Reviewed-on: https://go-review.googlesource.com/33165 Run-TryBot: Russ Cox <rsc@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Ian Lance Taylor <iant@golang.org> Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
2016-11-12 23:01:37 -05:00
fns := []string{"main.pt1.func1", "panic", "main.pt2.func1", "panic", "main.pt2", "main.pt1"}
for _, fn := range fns {
re := regexp.MustCompile(`(?m)^` + regexp.QuoteMeta(fn) + `\(.*\n`)
idx := re.FindStringIndex(output)
if idx == nil {
t.Fatalf("expected %q function in traceback:\n%s", fn, output)
}
output = output[idx[1]:]
}
}
func testPanicDeadlock(t *testing.T, name string, want string) {
// test issue 14432
output := runTestProg(t, "testprog", name)
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestPanicDeadlockGosched(t *testing.T) {
testPanicDeadlock(t, "GoschedInPanic", "panic: errorThatGosched\n\n")
}
func TestPanicDeadlockSyscall(t *testing.T) {
testPanicDeadlock(t, "SyscallInPanic", "1\n2\npanic: 3\n\n")
}
func TestPanicLoop(t *testing.T) {
output := runTestProg(t, "testprog", "PanicLoop")
if want := "panic while printing panic value"; !strings.Contains(output, want) {
t.Errorf("output does not contain %q:\n%s", want, output)
}
}
func TestMemPprof(t *testing.T) {
testenv.MustHaveGoRun(t)
exe, err := buildTestProg(t, "testprog")
if err != nil {
t.Fatal(err)
}
got, err := testenv.CleanCmdEnv(exec.Command(exe, "MemProf")).CombinedOutput()
if err != nil {
t.Fatal(err)
}
fn := strings.TrimSpace(string(got))
defer os.Remove(fn)
for try := 0; try < 2; try++ {
cmd := testenv.CleanCmdEnv(exec.Command(testenv.GoToolPath(t), "tool", "pprof", "-alloc_space", "-top"))
// Check that pprof works both with and without explicit executable on command line.
if try == 0 {
cmd.Args = append(cmd.Args, exe, fn)
} else {
cmd.Args = append(cmd.Args, fn)
}
found := false
for i, e := range cmd.Env {
if strings.HasPrefix(e, "PPROF_TMPDIR=") {
cmd.Env[i] = "PPROF_TMPDIR=" + os.TempDir()
found = true
break
}
}
if !found {
cmd.Env = append(cmd.Env, "PPROF_TMPDIR="+os.TempDir())
}
top, err := cmd.CombinedOutput()
t.Logf("%s:\n%s", cmd.Args, top)
if err != nil {
t.Error(err)
} else if !bytes.Contains(top, []byte("MemProf")) {
t.Error("missing MemProf in pprof output")
}
}
}
var concurrentMapTest = flag.Bool("run_concurrent_map_tests", false, "also run flaky concurrent map tests")
func TestConcurrentMapWrites(t *testing.T) {
if !*concurrentMapTest {
t.Skip("skipping without -run_concurrent_map_tests")
}
testenv.MustHaveGoRun(t)
output := runTestProg(t, "testprog", "concurrentMapWrites")
want := "fatal error: concurrent map writes"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestConcurrentMapReadWrite(t *testing.T) {
if !*concurrentMapTest {
t.Skip("skipping without -run_concurrent_map_tests")
}
testenv.MustHaveGoRun(t)
output := runTestProg(t, "testprog", "concurrentMapReadWrite")
want := "fatal error: concurrent map read and map write"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
func TestConcurrentMapIterateWrite(t *testing.T) {
if !*concurrentMapTest {
t.Skip("skipping without -run_concurrent_map_tests")
}
testenv.MustHaveGoRun(t)
output := runTestProg(t, "testprog", "concurrentMapIterateWrite")
want := "fatal error: concurrent map iteration and map write"
if !strings.HasPrefix(output, want) {
t.Fatalf("output does not start with %q:\n%s", want, output)
}
}
type point struct {
x, y *int
}
func (p *point) negate() {
*p.x = *p.x * -1
*p.y = *p.y * -1
}
// Test for issue #10152.
func TestPanicInlined(t *testing.T) {
defer func() {
r := recover()
if r == nil {
t.Fatalf("recover failed")
}
buf := make([]byte, 2048)
n := runtime.Stack(buf, false)
buf = buf[:n]
if !bytes.Contains(buf, []byte("(*point).negate(")) {
t.Fatalf("expecting stack trace to contain call to (*point).negate()")
}
}()
pt := new(point)
pt.negate()
}
// Test for issues #3934 and #20018.
// We want to delay exiting until a panic print is complete.
func TestPanicRace(t *testing.T) {
testenv.MustHaveGoRun(t)
exe, err := buildTestProg(t, "testprog")
if err != nil {
t.Fatal(err)
}
// The test is intentionally racy, and in my testing does not
// produce the expected output about 0.05% of the time.
// So run the program in a loop and only fail the test if we
// get the wrong output ten times in a row.
const tries = 10
retry:
for i := 0; i < tries; i++ {
got, err := testenv.CleanCmdEnv(exec.Command(exe, "PanicRace")).CombinedOutput()
if err == nil {
t.Logf("try %d: program exited successfully, should have failed", i+1)
continue
}
if i > 0 {
t.Logf("try %d:\n", i+1)
}
t.Logf("%s\n", got)
wants := []string{
"panic: crash",
"PanicRace",
"created by ",
}
for _, want := range wants {
if !bytes.Contains(got, []byte(want)) {
t.Logf("did not find expected string %q", want)
continue retry
}
}
// Test generated expected output.
return
}
t.Errorf("test ran %d times without producing expected output", tries)
}
runtime: print hexdump on traceback failure Currently, if anything goes wrong when printing a traceback, we simply cut off the traceback without any further diagnostics. Unfortunately, right now, we have a few issues that are difficult to debug because the traceback simply cuts off (#21431, #23484). This is an attempt to improve the debuggability of traceback failure by printing a diagnostic message plus a hex dump around the failed traceback frame when something goes wrong. The failures look like: goroutine 5 [running]: runtime: unexpected return pc for main.badLR2 called from 0xbad stack: frame={sp:0xc42004dfa8, fp:0xc42004dfc8} stack=[0xc42004d800,0xc42004e000) 000000c42004dea8: 0000000000000001 0000000000000001 000000c42004deb8: 000000c42004ded8 000000c42004ded8 000000c42004dec8: 0000000000427eea <runtime.dopanic+74> 000000c42004ded8 000000c42004ded8: 000000000044df70 <runtime.dopanic.func1+0> 000000c420001080 000000c42004dee8: 0000000000427b21 <runtime.gopanic+961> 000000c42004df08 000000c42004def8: 000000c42004df98 0000000000427b21 <runtime.gopanic+961> 000000c42004df08: 0000000000000000 0000000000000000 000000c42004df18: 0000000000000000 0000000000000000 000000c42004df28: 0000000000000000 0000000000000000 000000c42004df38: 0000000000000000 000000c420001080 000000c42004df48: 0000000000000000 0000000000000000 000000c42004df58: 0000000000000000 0000000000000000 000000c42004df68: 000000c4200010a0 0000000000000000 000000c42004df78: 00000000004c6400 00000000005031d0 000000c42004df88: 0000000000000000 0000000000000000 000000c42004df98: 000000c42004dfb8 00000000004ae7d9 <main.badLR2+73> 000000c42004dfa8: <00000000004c6400 00000000005031d0 000000c42004dfb8: 000000c42004dfd0 !0000000000000bad 000000c42004dfc8: >0000000000000000 0000000000000000 000000c42004dfd8: 0000000000451821 <runtime.goexit+1> 0000000000000000 000000c42004dfe8: 0000000000000000 0000000000000000 000000c42004dff8: 0000000000000000 main.badLR2(0x0) /go/src/runtime/testdata/testprog/badtraceback.go:42 +0x49 For #21431, #23484. Change-Id: I8718fc76ced81adb0b4b0b4f2293f3219ca80786 Reviewed-on: https://go-review.googlesource.com/89016 Run-TryBot: Austin Clements <austin@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Cherry Zhang <cherryyz@google.com>
2018-01-22 14:53:36 -05:00
func TestBadTraceback(t *testing.T) {
output := runTestProg(t, "testprog", "BadTraceback")
for _, want := range []string{
"runtime: unexpected return pc",
"called from 0xbad",
"00000bad", // Smashed LR in hex dump
"<main.badLR", // Symbolization in hex dump (badLR1 or badLR2)
} {
if !strings.Contains(output, want) {
t.Errorf("output does not contain %q:\n%s", want, output)
}
}
}
func TestTimePprof(t *testing.T) {
// Pass GOTRACEBACK for issue #41120 to try to get more
// information on timeout.
fn := runTestProg(t, "testprog", "TimeProf", "GOTRACEBACK=crash")
fn = strings.TrimSpace(fn)
defer os.Remove(fn)
cmd := testenv.CleanCmdEnv(exec.Command(testenv.GoToolPath(t), "tool", "pprof", "-top", "-nodecount=1", fn))
cmd.Env = append(cmd.Env, "PPROF_TMPDIR="+os.TempDir())
top, err := cmd.CombinedOutput()
t.Logf("%s", top)
if err != nil {
t.Error(err)
} else if bytes.Contains(top, []byte("ExternalCode")) {
t.Error("profiler refers to ExternalCode")
}
}
// Test that runtime.abort does so.
func TestAbort(t *testing.T) {
// Pass GOTRACEBACK to ensure we get runtime frames.
output := runTestProg(t, "testprog", "Abort", "GOTRACEBACK=system")
if want := "runtime.abort"; !strings.Contains(output, want) {
t.Errorf("output does not contain %q:\n%s", want, output)
}
if strings.Contains(output, "BAD") {
t.Errorf("output contains BAD:\n%s", output)
}
// Check that it's a signal traceback.
want := "PC="
// For systems that use a breakpoint, check specifically for that.
switch runtime.GOARCH {
case "386", "amd64":
switch runtime.GOOS {
case "plan9":
want = "sys: breakpoint"
case "windows":
want = "Exception 0x80000003"
default:
want = "SIGTRAP"
}
}
if !strings.Contains(output, want) {
t.Errorf("output does not contain %q:\n%s", want, output)
}
}
// For TestRuntimePanic: test a panic in the runtime package without
// involving the testing harness.
func init() {
if os.Getenv("GO_TEST_RUNTIME_PANIC") == "1" {
defer func() {
if r := recover(); r != nil {
// We expect to crash, so exit 0
// to indicate failure.
os.Exit(0)
}
}()
runtime.PanicForTesting(nil, 1)
// We expect to crash, so exit 0 to indicate failure.
os.Exit(0)
}
}
func TestRuntimePanic(t *testing.T) {
testenv.MustHaveExec(t)
cmd := testenv.CleanCmdEnv(exec.Command(os.Args[0], "-test.run=TestRuntimePanic"))
cmd.Env = append(cmd.Env, "GO_TEST_RUNTIME_PANIC=1")
out, err := cmd.CombinedOutput()
t.Logf("%s", out)
if err == nil {
t.Error("child process did not fail")
} else if want := "runtime.unexportedPanicForTesting"; !bytes.Contains(out, []byte(want)) {
t.Errorf("output did not contain expected string %q", want)
}
}
// Test that g0 stack overflows are handled gracefully.
func TestG0StackOverflow(t *testing.T) {
testenv.MustHaveExec(t)
switch runtime.GOOS {
case "darwin", "dragonfly", "freebsd", "linux", "netbsd", "openbsd", "android":
t.Skipf("g0 stack is wrong on pthread platforms (see golang.org/issue/26061)")
}
if os.Getenv("TEST_G0_STACK_OVERFLOW") != "1" {
cmd := testenv.CleanCmdEnv(exec.Command(os.Args[0], "-test.run=TestG0StackOverflow", "-test.v"))
cmd.Env = append(cmd.Env, "TEST_G0_STACK_OVERFLOW=1")
out, err := cmd.CombinedOutput()
// Don't check err since it's expected to crash.
if n := strings.Count(string(out), "morestack on g0\n"); n != 1 {
t.Fatalf("%s\n(exit status %v)", out, err)
}
// Check that it's a signal-style traceback.
if runtime.GOOS != "windows" {
if want := "PC="; !strings.Contains(string(out), want) {
t.Errorf("output does not contain %q:\n%s", want, out)
}
}
return
}
runtime.G0StackOverflow()
}
// Test that panic message is not clobbered.
// See issue 30150.
func TestDoublePanic(t *testing.T) {
output := runTestProg(t, "testprog", "DoublePanic", "GODEBUG=clobberfree=1")
wants := []string{"panic: XXX", "panic: YYY"}
for _, want := range wants {
if !strings.Contains(output, want) {
t.Errorf("output:\n%s\n\nwant output containing: %s", output, want)
}
}
}