testing, testing/synctest: report correct duration after panics

Report the correct wall-clock test duration after handling a
panic in a synctest.Test bubble.

Fixes #73852

Change-Id: I053262e5eac2dd9d5938b17c3093cbc3fa115a0d
Reviewed-on: https://go-review.googlesource.com/c/go/+/676695
Auto-Submit: Damien Neil <dneil@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>

diff --git a/src/testing/synctest/synctest.go b/src/testing/synctest/synctest.go
index a44047a9717550475f39b63d1b80de20bd56a657..57a6fbfbd6141e14bc7f13ad4a5986235aecd53d 100644 (file)
--- a/src/testing/synctest/synctest.go
+++ b/src/testing/synctest/synctest.go
@@ -273,13 +273,19 @@ import (
 //     associated with the bubble.
 //   - T.Run, T.Parallel, and T.Deadline must not be called.
 func Test(t *testing.T, f func(*testing.T)) {
+       var ok bool
        synctest.Run(func() {
-               testingSynctestTest(t, f)
+               ok = testingSynctestTest(t, f)
        })
+       if !ok {
+               // Fail the test outside the bubble,
+               // so test durations get set using real time.
+               t.FailNow()
+       }
 }
 
 //go:linkname testingSynctestTest testing/synctest.testingSynctestTest
-func testingSynctestTest(t *testing.T, f func(*testing.T))
+func testingSynctestTest(t *testing.T, f func(*testing.T)) bool
 
 // Wait blocks until every goroutine within the current bubble,
 // other than the current goroutine, is durably blocked.

diff --git a/src/testing/testing.go b/src/testing/testing.go
index 43ef9eef09b92555783cf6d5ea26cc6d61a267e3..b5305f29cc2f16eb33f008379a36f9cb7658e90e 100644 (file)
--- a/src/testing/testing.go
+++ b/src/testing/testing.go
@@ -1851,7 +1851,8 @@ func tRunner(t *T, fn func(t *T)) {
                                t.Logf("cleanup panicked with %v", r)
                        }
                        // Flush the output log up to the root before dying.
-                       for root := &t.common; root.parent != nil; root = root.parent {
+                       // Skip this if this *T is a synctest bubble, because we're not a subtest.
+                       for root := &t.common; !root.isSynctest && root.parent != nil; root = root.parent {
                                root.mu.Lock()
                                root.duration += highPrecisionTimeSince(root.start)
                                d := root.duration
@@ -2013,7 +2014,7 @@ func (t *T) Run(name string, f func(t *T)) bool {
 // It is called by synctest.Test, from within an already-created bubble.
 //
 //go:linkname testingSynctestTest testing/synctest.testingSynctestTest
-func testingSynctestTest(t *T, f func(*T)) {
+func testingSynctestTest(t *T, f func(*T)) (ok bool) {
        if t.cleanupStarted.Load() {
                panic("testing: synctest.Run called during t.Cleanup")
        }
@@ -2044,6 +2045,7 @@ func testingSynctestTest(t *T, f func(*T)) {
                // parent tests by one of the subtests. Continue aborting up the chain.
                runtime.Goexit()
        }
+       return !t2.failed
 }
 
 // Deadline reports the time at which the test binary will have