diff --git a/src/runtime/crash_test.go b/src/runtime/crash_test.go index 2eddbcaefc..9ba45b8f2a 100644 --- a/src/runtime/crash_test.go +++ b/src/runtime/crash_test.go @@ -6,16 +6,21 @@ package runtime_test import ( "bytes" + "context" "errors" "flag" "fmt" + "internal/goexperiment" "internal/testenv" + tracev2 "internal/trace/v2" + "io" "log" "os" "os/exec" "path/filepath" "regexp" "runtime" + "runtime/trace" "strings" "sync" "testing" @@ -874,6 +879,71 @@ func TestG0StackOverflow(t *testing.T) { runtime.G0StackOverflow() } +// For TestCrashWhileTracing: test a panic without involving the testing +// harness, as we rely on stdout only containing trace output. +func init() { + if os.Getenv("TEST_CRASH_WHILE_TRACING") == "1" { + trace.Start(os.Stdout) + trace.Log(context.Background(), "xyzzy-cat", "xyzzy-msg") + panic("yzzyx") + } +} + +func TestCrashWhileTracing(t *testing.T) { + if !goexperiment.ExecTracer2 { + t.Skip("skipping because this test is incompatible with the legacy tracer") + } + + testenv.MustHaveExec(t) + + cmd := testenv.CleanCmdEnv(testenv.Command(t, os.Args[0])) + cmd.Env = append(cmd.Env, "TEST_CRASH_WHILE_TRACING=1") + stdOut, err := cmd.StdoutPipe() + var errOut bytes.Buffer + cmd.Stderr = &errOut + + if err := cmd.Start(); err != nil { + t.Fatalf("could not start subprocess: %v", err) + } + r, err := tracev2.NewReader(stdOut) + if err != nil { + t.Fatalf("could not create trace.NewReader: %v", err) + } + var seen bool + i := 1 +loop: + for ; ; i++ { + ev, err := r.ReadEvent() + if err != nil { + if err != io.EOF { + t.Errorf("error at event %d: %v", i, err) + } + break loop + } + switch ev.Kind() { + case tracev2.EventLog: + v := ev.Log() + if v.Category == "xyzzy-cat" && v.Message == "xyzzy-msg" { + // Should we already stop reading here? More events may come, but + // we're not guaranteeing a fully unbroken trace until the last + // byte... + seen = true + } + } + } + if err := cmd.Wait(); err == nil { + t.Error("the process should have panicked") + } + if !seen { + t.Errorf("expected one matching log event matching, but none of the %d received trace events match", i) + } + t.Logf("stderr output:\n%s", errOut.String()) + needle := "yzzyx\n" + if n := strings.Count(errOut.String(), needle); n != 1 { + t.Fatalf("did not find expected panic message %q\n(exit status %v)", needle, err) + } +} + // Test that panic message is not clobbered. // See issue 30150. func TestDoublePanic(t *testing.T) { diff --git a/src/runtime/panic.go b/src/runtime/panic.go index e6d1c5d908..99eb1c3e23 100644 --- a/src/runtime/panic.go +++ b/src/runtime/panic.go @@ -759,6 +759,16 @@ func gopanic(e any) { fn() } + // If we're tracing, flush the current generation to make the trace more + // readable. + // + // TODO(aktau): Handle a panic from within traceAdvance more gracefully. + // Currently it would hang. Not handled now because it is very unlikely, and + // already unrecoverable. + if traceEnabled() { + traceAdvance(false) + } + // ran out of deferred calls - old-school panic now // Because it is unsafe to call arbitrary user code after freezing // the world, we call preprintpanics to invoke all necessary Error diff --git a/src/runtime/trace.go b/src/runtime/trace.go index a9cfa22337..948a8da0ca 100644 --- a/src/runtime/trace.go +++ b/src/runtime/trace.go @@ -578,6 +578,9 @@ func StopTrace() { }) } +// traceAdvance is called from panic, it does nothing for the legacy tracer. +func traceAdvance(stopTrace bool) {} + // ReadTrace returns the next chunk of binary tracing data, blocking until data // is available. If tracing is turned off and all the data accumulated while it // was on has been returned, ReadTrace returns nil. The caller must copy the