Panic when a test times out (#3749)

By calling `panic` when a Bazel test times out, which is indicated by
Bazel sending a SIGTERM, stack traces of all Go routines are printed,
similar to the behavior of native `go test`.

go/tools/builders/generate_test_main.go

@@ -235,7 +235,7 @@ func main() {
 		}
 	}
 	{{end}}
-
+	bzltestutil.RegisterTimeoutHandler()
 	{{if not .TestMain}}
 	res := m.Run()
 	{{else}}

go/tools/bzltestutil/BUILD.bazel

@@ -5,6 +5,7 @@ go_tool_library(
     srcs = [
         "lcov.go",
         "test2json.go",
+        "timeout.go",
         "wrap.go",
         "xml.go",
     ],

go/tools/bzltestutil/timeout.go

@@ -0,0 +1,36 @@
+// Copyright 2020 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package bzltestutil
+
+import (
+	"os"
+	"os/signal"
+	"runtime/debug"
+	"syscall"
+)
+
+func RegisterTimeoutHandler() {
+	go func() {
+		// When the Bazel test timeout is reached, Bazel sends a SIGTERM. We
+		// panic just like native go test would so that the user gets stack
+		// traces of all running go routines.
+		// See https://github.com/golang/go/blob/e816eb50140841c524fd07ecb4eaa078954eb47c/src/testing/testing.go#L2351
+		c := make(chan os.Signal, 1)
+		signal.Notify(c, syscall.SIGTERM)
+		<-c
+		debug.SetTraceback("all")
+		panic("test timed out")
+	}()
+}

go/tools/bzltestutil/wrap.go

@@ -23,10 +23,12 @@ import (
 	"log"
 	"os"
 	"os/exec"
+	"os/signal"
 	"path/filepath"
 	"strconv"
 	"strings"
 	"sync"
+	"syscall"
 
 	"github.com/bazelbuild/rules_go/go/tools/bzltestutil/chdir"
 )
@@ -67,9 +69,9 @@ func shouldAddTestV() bool {
 // ensure that one line at a time is written to the inner writer.
 type streamMerger struct {
 	OutW, ErrW *io.PipeWriter
-	mutex sync.Mutex
-	inner io.Writer
-	wg sync.WaitGroup
+	mutex      sync.Mutex
+	inner      io.Writer
+	wg         sync.WaitGroup
 	outR, errR *bufio.Reader
 }
 
@@ -78,10 +80,10 @@ func NewStreamMerger(w io.Writer) *streamMerger {
 	errR, errW := io.Pipe()
 	return &streamMerger{
 		inner: w,
-		OutW: outW,
-		ErrW: errW,
-		outR: bufio.NewReader(outR),
-		errR: bufio.NewReader(errR),
+		OutW:  outW,
+		ErrW:  errW,
+		outR:  bufio.NewReader(outR),
+		errR:  bufio.NewReader(errR),
 	}
 }
 
@@ -126,6 +128,17 @@ func Wrap(pkg string) error {
 	cmd.Env = append(os.Environ(), "GO_TEST_WRAP=0")
 	cmd.Stderr = io.MultiWriter(os.Stderr, streamMerger.ErrW)
 	cmd.Stdout = io.MultiWriter(os.Stdout, streamMerger.OutW)
+	go func() {
+		// When the Bazel test timeout is reached, Bazel sends a SIGTERM that
+		// we need to forward to the inner process.
+		// TODO: This never triggers on Windows, even though Go should simulate
+		//  a SIGTERM when Windows asks the process to close. It is not clear
+		//  whether Bazel uses the required graceful shutdown mechanism.
+		c := make(chan os.Signal, 1)
+		signal.Notify(c, syscall.SIGTERM)
+		<-c
+		cmd.Process.Signal(syscall.SIGTERM)
+	}()
 	streamMerger.Start()
 	err := cmd.Run()
 	streamMerger.ErrW.Close()

tests/core/go_test/BUILD.bazel

@@ -263,4 +263,9 @@ go_bazel_test(
 go_bazel_test(
     name = "filter_test_cases_test",
     srcs = ["filter_test_cases_test.go"],
-)
+)
+
+go_bazel_test(
+    name = "timeout_test",
+    srcs = ["timeout_test.go"],
+)

tests/core/go_test/timeout_test.go

@@ -0,0 +1,66 @@
+package timeout_test
+
+import (
+	"os"
+	"path/filepath"
+	"runtime"
+	"strings"
+	"testing"
+
+	"github.com/bazelbuild/rules_go/go/tools/bazel_testing"
+)
+
+func TestMain(m *testing.M) {
+	bazel_testing.TestMain(m, bazel_testing.Args{
+		Main: `
+-- BUILD.bazel --
+load("@io_bazel_rules_go//go:def.bzl", "go_test")
+
+go_test(
+	name = "timeout_test",
+	srcs = ["timeout_test.go"],
+)
+-- timeout_test.go --
+package timeout
+
+import "testing"
+
+func TestFoo(t *testing.T) {
+	neverTerminates()
+}
+
+func neverTerminates() {
+	for {}
+}
+`,
+	})
+}
+
+func TestTimeout(t *testing.T) {
+	if runtime.GOOS == "windows" {
+		t.Skip("panics on timeouts are not yet supported on Windows")
+	}
+
+	if err := bazel_testing.RunBazel("test", "//:timeout_test", "--test_timeout=3"); err == nil {
+		t.Fatal("expected bazel test to fail")
+	} else if exitErr, ok := err.(*bazel_testing.StderrExitError); !ok || exitErr.Err.ExitCode() != 3 {
+		t.Fatalf("expected bazel test to fail with exit code 3", err)
+	}
+	p, err := bazel_testing.BazelOutput("info", "bazel-testlogs")
+	if err != nil {
+		t.Fatalf("could not find testlogs root: %s", err)
+	}
+	path := filepath.Join(strings.TrimSpace(string(p)), "timeout_test/test.log")
+	b, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatalf("could not read test log: %s", err)
+	}
+
+	testLog := string(b)
+	if !strings.Contains(testLog, "panic: test timed out") {
+		t.Fatalf("test log does not contain expected panic:\n%s", testLog)
+	}
+	if !strings.Contains(testLog, "timeout_test.neverTerminates(") {
+		t.Fatalf("test log does not contain expected stack trace:\n%s", testLog)
+	}
+}