1
0
mirror of https://github.com/golang/go synced 2024-11-17 14:04:48 -07:00

testing: print names of running tests on test timeout

Track the running tests and when they started,
so that we can report the running tests on a test timeout.

	% go test -timeout=5s
	panic: test timed out after 5s
	running tests:
		TestTCPSpuriousConnSetupCompletion (4s)

	... stack traces as usual ...

	% go test -run=Script -timeout=10s cmd/go
	vcs-test.golang.org rerouted to http://127.0.0.1:65168
	https://vcs-test.golang.org rerouted to https://127.0.0.1:65169
	go test proxy running at GOPROXY=http://127.0.0.1:65170/mod
	panic: test timed out after 10s
	running tests:
		TestScript (10s)
		TestScript/mod_get_patchcycle (0s)
		TestScript/mod_get_prefer_incompatible (0s)
		TestScript/mod_get_promote_implicit (0s)
		TestScript/mod_get_pseudo (0s)
		TestScript/mod_get_pseudo_other_branch (0s)
		TestScript/mod_get_pseudo_prefix (0s)
		TestScript/mod_get_test (0s)
		TestScript/mod_get_trailing_slash (0s)
		TestScript/mod_get_update_unrelated_sum (0s)
		TestScript/mod_gobuild_import (0s)
		TestScript/mod_gomodcache (0s)
		TestScript/mod_gonoproxy (0s)
		TestScript/mod_load_badchain (0s)
		TestScript/mod_overlay (0s)
		TestScript/test_fuzz_minimize (6s)
		TestScript/test_fuzz_minimize_dirty_cov (7s)

	... stack traces as usual ...

Change-Id: I3a6647c029097becc06664ebd76a2597c7ed7b8e
Reviewed-on: https://go-review.googlesource.com/c/go/+/446176
Run-TryBot: Russ Cox <rsc@golang.org>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
Auto-Submit: Russ Cox <rsc@golang.org>
This commit is contained in:
Russ Cox 2022-10-28 09:19:32 -04:00 committed by Gopher Robot
parent 02cffcde17
commit ad5d2f64fb

View File

@ -381,6 +381,7 @@ import (
"runtime"
"runtime/debug"
"runtime/trace"
"sort"
"strconv"
"strings"
"sync"
@ -477,6 +478,8 @@ var (
testlogFile *os.File
numFailed atomic.Uint32 // number of test failures
running sync.Map // map[string]time.Time of running, unpaused tests
)
type chattyFlag struct {
@ -1363,6 +1366,7 @@ func (t *T) Parallel() {
if t.chatty != nil {
t.chatty.Updatef(t.name, "=== PAUSE %s\n", t.name)
}
running.Delete(t.name)
t.signal <- true // Release calling test.
<-t.parent.barrier // Wait for the parent test to complete.
@ -1371,6 +1375,7 @@ func (t *T) Parallel() {
if t.chatty != nil {
t.chatty.Updatef(t.name, "=== CONT %s\n", t.name)
}
running.Store(t.name, time.Now())
t.start = time.Now()
t.raceErrors += -race.Errors()
@ -1474,15 +1479,16 @@ func tRunner(t *T, fn func(t *T)) {
// complete even if a cleanup function calls t.FailNow. See issue 41355.
didPanic := false
defer func() {
// Only report that the test is complete if it doesn't panic,
// as otherwise the test binary can exit before the panic is
// reported to the user. See issue 41479.
if didPanic {
return
}
if err != nil {
panic(err)
}
// Only report that the test is complete if it doesn't panic,
// as otherwise the test binary can exit before the panic is
// reported to the user. See issue 41479.
running.Delete(t.name)
t.signal <- signal
}()
@ -1595,6 +1601,8 @@ func (t *T) Run(name string, f func(t *T)) bool {
if t.chatty != nil {
t.chatty.Updatef(t.name, "=== RUN %s\n", t.name)
}
running.Store(t.name, time.Now())
// Instead of reducing the running count of this test before calling the
// tRunner and increasing it afterwards, we rely on tRunner keeping the
// count correct. This ensures that a sequence of sequential tests runs
@ -2201,11 +2209,33 @@ func (m *M) startAlarm() time.Time {
m.timer = time.AfterFunc(*timeout, func() {
m.after()
debug.SetTraceback("all")
panic(fmt.Sprintf("test timed out after %v", *timeout))
extra := ""
if list := runningList(); len(list) > 0 {
var b strings.Builder
b.WriteString("\nrunning tests:")
for _, name := range list {
b.WriteString("\n\t")
b.WriteString(name)
}
extra = b.String()
}
panic(fmt.Sprintf("test timed out after %v%s", *timeout, extra))
})
return deadline
}
// runningList returns the list of running tests.
func runningList() []string {
var list []string
running.Range(func(k, v any) bool {
list = append(list, fmt.Sprintf("%s (%v)", k.(string), time.Since(v.(time.Time)).Round(time.Second)))
return true
})
sort.Strings(list)
return list
}
// stopAlarm turns off the alarm.
func (m *M) stopAlarm() {
if *timeout > 0 {