testing: provide additional information when test funcs panic

Flush the output log up to the root when a test panics. Prior to
this change, only the current test's output log was flushed to its
parent, resulting in no output when a subtest panics.

For the following test function:

	func Test(t *testing.T) {
		for i, test := range []int{1, 0, 2} {
			t.Run(fmt.Sprintf("%v/%v", i, test), func(t *testing.T) {
				_ = 1 / test
			})
		}
	}

Output before this change:

	panic: runtime error: integer divide by zero [recovered]
		panic: runtime error: integer divide by zero
	(stack trace follows)

Output after this change:

	--- FAIL: Test (0.00s)
	    --- FAIL: Test/1/0 (0.00s)
	panic: runtime error: integer divide by zero [recovered]
	(stack trace follows)

Fixes #32121

Change-Id: Ifee07ccc005f0493a902190a8be734943123b6b7
Reviewed-on: https://go-review.googlesource.com/c/go/+/179599
Run-TryBot: Damien Neil <dneil@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
This commit is contained in:
Damien Neil 2019-05-30 09:46:56 -07:00
parent cd18da451f
commit 81a74b4e8d
4 changed files with 130 additions and 2 deletions

View file

@ -860,7 +860,6 @@ func tRunner(t *T, fn func(t *T)) {
t.Errorf("race detected during execution of test")
}
t.duration += time.Since(t.start)
// If the test panicked, print any test output before dying.
err := recover()
signal := true
@ -877,10 +876,20 @@ func tRunner(t *T, fn func(t *T)) {
}
if err != nil {
t.Fail()
t.report()
// Flush the output log up to the root before dying.
t.mu.Lock()
root := &t.common
for ; root.parent != nil; root = root.parent {
root.duration += time.Since(root.start)
fmt.Fprintf(root.parent.w, "--- FAIL: %s (%s)\n", root.name, fmtDuration(root.duration))
root.parent.mu.Lock()
io.Copy(root.parent.w, bytes.NewReader(root.output))
}
panic(err)
}
t.duration += time.Since(t.start)
if len(t.sub) > 0 {
// Run parallel subtests.
// Decrease the running count for this test.