Skip to content

Commit

Permalink
Print stack traces without panicking on test timeout
Browse files Browse the repository at this point in the history
  • Loading branch information
fmeum committed Jan 16, 2024
1 parent 31549c1 commit 20703d8
Show file tree
Hide file tree
Showing 4 changed files with 61 additions and 9 deletions.
15 changes: 9 additions & 6 deletions go/tools/bzltestutil/timeout.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,22 +15,25 @@
package bzltestutil

import (
"fmt"
"os"
"os/signal"
"runtime/debug"
"runtime"
"syscall"
)

func RegisterTimeoutHandler() {
// 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.
// When the Bazel test timeout is reached, Bazel sends a SIGTERM. We print stack traces for all
// goroutines just like native go test would. We do not panic (like native go test does) because
// users may legitimately want to use SIGTERM in tests and prints are less disruptive than
// panics in that case.
// See https://github.com/golang/go/blob/e816eb50140841c524fd07ecb4eaa078954eb47c/src/testing/testing.go#L2351
c := make(chan os.Signal, 1)
signal.Notify(c, syscall.SIGTERM)
go func() {
<-c
debug.SetTraceback("all")
panic("test timed out")
buf := make([]byte, 1<<20)
stacklen := runtime.Stack(buf, true)
fmt.Printf("Received SIGTERM, printing stack traces of all goroutines:\n%s", buf[:stacklen])
}()
}
9 changes: 9 additions & 0 deletions tests/core/go_test/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -250,6 +250,15 @@ go_test(
shard_count = 2,
)

go_test(
name = "sigterm_handler_test",
srcs = ["sigterm_handler_test.go"],
target_compatible_with = select({
"@platforms//os:windows": ["@platforms//:incompatible"],
"//conditions:default": [],
}),
)

go_bazel_test(
name = "env_inherit_test",
srcs = ["env_inherit_test.go"],
Expand Down
40 changes: 40 additions & 0 deletions tests/core/go_test/sigterm_handler_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
package sigterm_handler_test

import (
"os"
"os/signal"
"sync"
"syscall"
"testing"
"time"
)

func TestRegisterSignalHandler(t *testing.T) {
called := false
var wg sync.WaitGroup

wg.Add(1)

c := make(chan os.Signal, 1)
signal.Notify(c, syscall.SIGTERM)

go func() {
switch <-c {
case syscall.SIGTERM:
called = true
wg.Done()
}
}()

if err := syscall.Kill(os.Getpid(), syscall.SIGTERM); err != nil {
t.Fatalf("Failed to send SIGTERM: %v", err)
}
wg.Wait()

// Give any signal handlers registered by rules_go a chance to run.
time.Sleep(1 * time.Second)

if !called {
t.Fatal("Our handler has not run")
}
}
6 changes: 3 additions & 3 deletions tests/core/go_test/timeout_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ func neverTerminates() {

func TestTimeout(t *testing.T) {
if runtime.GOOS == "windows" {
t.Skip("panics on timeouts are not yet supported on Windows")
t.Skip("stack traces on timeouts are not yet supported on Windows")
}

if err := bazel_testing.RunBazel("test", "//:timeout_test", "--test_timeout=3"); err == nil {
Expand All @@ -57,8 +57,8 @@ func TestTimeout(t *testing.T) {
}

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, "Received SIGTERM, printing stack traces of all goroutines:") {
t.Fatalf("test log does not contain expected header:\n%s", testLog)
}
if !strings.Contains(testLog, "timeout_test.neverTerminates(") {
t.Fatalf("test log does not contain expected stack trace:\n%s", testLog)
Expand Down

0 comments on commit 20703d8

Please sign in to comment.