testing: show in-progress tests upon SIGINT

Because of parallel tests, which have stalled executions, the RUN
output of a test can be much earlier than its completion output resulting
in hard-to-read verbose output.

The tests are displayed in the order in which the output shows
that they began, to make it easy to line up with the "RUN" output.
Similarly, the definitions of when tests begin and complete is
determined by when RUN and FAIL/SKIP/PASS are output since the
focus of this code is on enhancing readability.

Fixes #19397

Change-Id: I4d0ca3fd268b620484e7a190117f79a33b3dc461
Reviewed-on: https://go-review.googlesource.com/44352
Run-TryBot: Ian Lance Taylor <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>

src/cmd/go/go_test.go

@@ -2564,6 +2564,17 @@ func TestGoTestFlagsAfterPackage(t *testing.T) {
 	tg.run("test", "-v", "testdata/flag_test.go", "-args", "-v=7") // Two distinct -v flags.
 }
 
+func TestGoTestShowInProgressOnInterrupt(t *testing.T) {
+	if runtime.GOOS == "windows" || runtime.GOOS == "plan9" {
+		t.Skipf("skipping test on %s - lack of full unix-like signal support", runtime.GOOS)
+	}
+	tg := testgo(t)
+	defer tg.cleanup()
+	tg.run("test", "-v", "testdata/inprogress_interrupt_test.go")
+	testsInProgress := "tests in progress: TestParallel, TestSerial"
+	tg.grepStdout(testsInProgress, "tests which haven't completed should be listed in progress")
+}
+
 func TestGoTestXtestonlyWorks(t *testing.T) {
 	tg := testgo(t)
 	defer tg.cleanup()

src/cmd/go/testdata/inprogress_interrupt_test.go

@@ -0,0 +1,40 @@
+// Copyright 2017 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 inprogress_interrupt_test
+
+import (
+	"os"
+	"os/signal"
+	"sync"
+	"syscall"
+	"testing"
+)
+
+func TestParallel(t *testing.T) {
+	t.Parallel()
+}
+
+func TestSerial(t *testing.T) {
+	sigCh := make(chan os.Signal, 1)
+	signal.Notify(sigCh, os.Interrupt)
+
+	var wg sync.WaitGroup
+	wg.Add(1)
+	go func() {
+		<-sigCh // catch initial signal
+		<-sigCh // catch propagated signal
+		wg.Done()
+	}()
+
+	proc, err := os.FindProcess(syscall.Getpid())
+	if err != nil {
+		t.Fatalf("unable to find current process: %v", err)
+	}
+	err = proc.Signal(os.Interrupt)
+	if err != nil {
+		t.Fatalf("failed to interrupt current process: %v", err)
+	}
+
+	wg.Wait()
+}

src/go/build/deps_test.go

@@ -183,7 +183,7 @@ var pkgDeps = map[string][]string{
 	"runtime/trace":  {"L0"},
 	"text/tabwriter": {"L2"},
 
-	"testing":          {"L2", "flag", "fmt", "internal/race", "os", "runtime/debug", "runtime/pprof", "runtime/trace", "time"},
+	"testing":          {"L2", "flag", "fmt", "internal/race", "os", "os/signal", "runtime/debug", "runtime/pprof", "runtime/trace", "syscall", "time"},
 	"testing/iotest":   {"L2", "log"},
 	"testing/quick":    {"L2", "flag", "fmt", "reflect", "time"},
 	"internal/testenv": {"L2", "OS", "flag", "testing", "syscall"},

src/os/signal/signal_plan9_test.go

@@ -2,10 +2,11 @@
 // Use of this source code is governed by a BSD-style
 // license that can be found in the LICENSE file.
 
-package signal
+package signal_test
 
 import (
 	"os"
+	. "os/signal"
 	"runtime"
 	"syscall"
 	"testing"

src/os/signal/signal_test.go

@@ -4,13 +4,14 @@
 
 // +build darwin dragonfly freebsd linux netbsd openbsd solaris
 
-package signal
+package signal_test
 
 import (
 	"flag"
 	"io/ioutil"
 	"os"
 	"os/exec"
+	. "os/signal"
 	"runtime"
 	"strconv"
 	"syscall"

src/os/signal/signal_windows_test.go

@@ -2,7 +2,7 @@
 // Use of this source code is governed by a BSD-style
 // license that can be found in the LICENSE file.
 
-package signal
+package signal_test
 
 import (
 	"bytes"

src/testing/testing.go

@@ -224,13 +224,16 @@ import (
 	"internal/race"
 	"io"
 	"os"
+	"os/signal"
 	"runtime"
 	"runtime/debug"
 	"runtime/trace"
+	"sort"
 	"strconv"
 	"strings"
 	"sync"
 	"sync/atomic"
+	"syscall"
 	"time"
 )
 
@@ -269,6 +272,10 @@ var (
 	haveExamples bool // are there examples?
 
 	cpuList []int
+
+	inProgressMu       sync.Mutex // guards this group of fields
+	inProgressRegistry = make(map[string]int)
+	inProgressIdx      int
 )
 
 // common holds the elements common between T and B and
@@ -778,9 +785,12 @@ func (t *T) Run(name string, f func(t *T)) bool {
 		root := t.parent
 		for ; root.parent != nil; root = root.parent {
 		}
+		inProgressMu.Lock()
 		root.mu.Lock()
+		t.registerInProgress()
 		fmt.Fprintf(root.w, "=== RUN   %s\n", t.name)
 		root.mu.Unlock()
+		inProgressMu.Unlock()
 	}
 	// Instead of reducing the running count of this test before calling the
 	// tRunner and increasing it afterwards, we rely on tRunner keeping the
@@ -942,6 +952,11 @@ func (t *T) report() {
 	}
 	dstr := fmtDuration(t.duration)
 	format := "--- %s: %s (%s)\n"
+
+	inProgressMu.Lock()
+	defer inProgressMu.Unlock()
+	defer t.registerComplete()
+
 	if t.Failed() {
 		t.flushToParent(format, "FAIL", t.name, dstr)
 	} else if t.chatty {
@@ -953,6 +968,39 @@ func (t *T) report() {
 	}
 }
 
+func (t *T) registerInProgress() {
+	if !t.chatty {
+		return
+	}
+	inProgressRegistry[t.name] = inProgressIdx
+	inProgressIdx++
+}
+
+func (t *T) registerComplete() {
+	if !t.chatty {
+		return
+	}
+	delete(inProgressRegistry, t.name)
+}
+
+func reportTestsInProgress() {
+	if len(inProgressRegistry) == 0 {
+		return
+	}
+	idxToName := make(map[int]string)
+	var indexes []int
+	for name, idx := range inProgressRegistry {
+		idxToName[idx] = name
+		indexes = append(indexes, idx)
+	}
+	sort.Ints(indexes)
+	var namesInOrder []string
+	for _, idx := range indexes {
+		namesInOrder = append(namesInOrder, idxToName[idx])
+	}
+	fmt.Printf("\ntests in progress: %s\n", strings.Join(namesInOrder, ", "))
+}
+
 func listTests(matchString func(pat, str string) (bool, error), tests []InternalTest, benchmarks []InternalBenchmark, examples []InternalExample) {
 	if _, err := matchString(*matchList, "non-empty"); err != nil {
 		fmt.Fprintf(os.Stderr, "testing: invalid regexp in -test.list (%q): %s\n", *matchList, err)
@@ -1056,6 +1104,24 @@ func (m *M) before() {
 		fmt.Fprintf(os.Stderr, "testing: cannot use -test.coverprofile because test binary was not built with coverage enabled\n")
 		os.Exit(2)
 	}
+	if Verbose() {
+		sigCh := make(chan os.Signal, 1)
+		signal.Notify(sigCh, os.Interrupt)
+		go func() {
+			<-sigCh
+			signal.Stop(sigCh)
+			inProgressMu.Lock()
+			reportTestsInProgress()
+			inProgressMu.Unlock()
+			proc, err := os.FindProcess(syscall.Getpid())
+			if err == nil {
+				err = proc.Signal(os.Interrupt)
+			}
+			if err != nil {
+				os.Exit(2)
+			}
+		}()
+	}
 }
 
 // after runs after all testing.