bench bool // Whether the current test is a benchmark.
hasSub atomic.Bool // whether there are sub-benchmarks.
cleanupStarted atomic.Bool // Registered cleanup callbacks have started to execute
- raceErrors int // Number of races detected during test.
runner string // Function name of tRunner running the test.
isParallel bool // Whether the test is parallel.
signal chan bool // To signal a test is done.
sub []*T // Queue of subtests to be run in parallel.
+ lastRaceErrors atomic.Int64 // Max value of race.Errors seen during the test or its subtests.
+ raceErrorLogged atomic.Bool
+
tempDirMu sync.Mutex
tempDir string
tempDirErr error
// Failed reports whether the function has failed.
func (c *common) Failed() bool {
c.mu.RLock()
- failed := c.failed
- c.mu.RUnlock()
- return failed || c.raceErrors+race.Errors() > 0
+ defer c.mu.RUnlock()
+
+ if !c.done && int64(race.Errors()) > c.lastRaceErrors.Load() {
+ c.mu.RUnlock()
+ c.checkRaces()
+ c.mu.RLock()
+ }
+
+ return c.failed
}
// FailNow marks the function as having failed and stops its execution
}
}
+// resetRaces updates c.parent's count of data race errors (or the global count,
+// if c has no parent), and updates c.lastRaceErrors to match.
+//
+// Any races that occurred prior to this call to resetRaces will
+// not be attributed to c.
+func (c *common) resetRaces() {
+ if c.parent == nil {
+ c.lastRaceErrors.Store(int64(race.Errors()))
+ } else {
+ c.lastRaceErrors.Store(c.parent.checkRaces())
+ }
+}
+
+// checkRaces checks whether the global count of data race errors has increased
+// since c's count was last reset.
+//
+// If so, it marks c as having failed due to those races (logging an error for
+// the first such race), and updates the race counts for the parents of c so
+// that if they are currently suspended (such as in a call to T.Run) they will
+// not log separate errors for the race(s).
+//
+// Note that multiple tests may be marked as failed due to the same race if they
+// are executing in parallel.
+func (c *common) checkRaces() (raceErrors int64) {
+ raceErrors = int64(race.Errors())
+ for {
+ last := c.lastRaceErrors.Load()
+ if raceErrors <= last {
+ // All races have already been reported.
+ return raceErrors
+ }
+ if c.lastRaceErrors.CompareAndSwap(last, raceErrors) {
+ break
+ }
+ }
+
+ if c.raceErrorLogged.CompareAndSwap(false, true) {
+ // This is the first race we've encountered for this test.
+ // Mark the test as failed, and log the reason why only once.
+ // (Note that the race detector itself will still write a goroutine
+ // dump for any further races it detects.)
+ c.Errorf("race detected during execution of test")
+ }
+
+ // Update the parent(s) of this test so that they don't re-report the race.
+ parent := c.parent
+ for parent != nil {
+ for {
+ last := parent.lastRaceErrors.Load()
+ if raceErrors <= last {
+ // This race was already reported by another (likely parallel) subtest.
+ return raceErrors
+ }
+ if parent.lastRaceErrors.CompareAndSwap(last, raceErrors) {
+ break
+ }
+ }
+ parent = parent.parent
+ }
+
+ return raceErrors
+}
+
// callerName gives the function name (qualified with a package path)
// for the caller after skip frames (where 0 means the current function).
func callerName(skip int) string {
// Add to the list of tests to be released by the parent.
t.parent.sub = append(t.parent.sub, t)
- t.raceErrors += race.Errors()
+
+ // Report any races during execution of this test up to this point.
+ //
+ // We will assume that any races that occur between here and the point where
+ // we unblock are not caused by this subtest. That assumption usually holds,
+ // although it can be wrong if the test spawns a goroutine that races in the
+ // background while the rest of the test is blocked on the call to Parallel.
+ // If that happens, we will misattribute the background race to some other
+ // test, or to no test at all — but that false-negative is so unlikely that it
+ // is not worth adding race-report noise for the common case where the test is
+ // completely suspended during the call to Parallel.
+ t.checkRaces()
if t.chatty != nil {
t.chatty.Updatef(t.name, "=== PAUSE %s\n", t.name)
t.chatty.Updatef(t.name, "=== CONT %s\n", t.name)
}
running.Store(t.name, time.Now())
-
t.start = time.Now()
- t.raceErrors += -race.Errors()
+
+ // Reset the local race counter to ignore any races that happened while this
+ // goroutine was blocked, such as in the parent test or in other parallel
+ // subtests.
+ //
+ // (Note that we don't call parent.checkRaces here:
+ // if other parallel subtests have already introduced races, we want to
+ // let them report those races instead of attributing them to the parent.)
+ t.lastRaceErrors.Store(int64(race.Errors()))
}
// Setenv calls os.Setenv(key, value) and uses Cleanup to
// a call to runtime.Goexit, record the duration and send
// a signal saying that the test is done.
defer func() {
+ t.checkRaces()
+
+ // TODO(#61034): This is the wrong place for this check.
if t.Failed() {
numFailed.Add(1)
}
- if t.raceErrors+race.Errors() > 0 {
- t.Errorf("race detected during execution of test")
- }
-
// Check if the test panicked or Goexited inappropriately.
//
// If this happens in a normal test, print output but continue panicking.
if err != nil {
doPanic(err)
}
+ t.checkRaces()
if !t.isParallel {
// Reacquire the count for sequential tests. See comment in Run.
t.context.waitParallel()
}()
t.start = time.Now()
- t.raceErrors = -race.Errors()
+ t.resetRaces()
fn(t)
// code beyond here will not be executed when FailNow is invoked
testOk = false
}
}
- if !testOk || !exampleOk || !fuzzTargetsOk || !runBenchmarks(m.deps.ImportPath(), m.deps.MatchString, m.benchmarks) || race.Errors() > 0 {
+ anyFailed := !testOk || !exampleOk || !fuzzTargetsOk || !runBenchmarks(m.deps.ImportPath(), m.deps.MatchString, m.benchmarks)
+ if !anyFailed && race.Errors() > 0 {
+ fmt.Print(chatty.prefix(), "testing: race detected outside of test execution\n")
+ anyFailed = true
+ }
+ if anyFailed {
fmt.Print(chatty.prefix(), "FAIL\n")
m.exitCode = 1
return
import (
"bytes"
+ "internal/race"
"internal/testenv"
"os"
"path/filepath"
+ "regexp"
+ "sync"
"testing"
)
// standard library with a TestMain, so that code is executed.
func TestMain(m *testing.M) {
- os.Exit(m.Run())
+ if os.Getenv("GO_WANT_RACE_BEFORE_TESTS") == "1" {
+ doRace()
+ }
+
+ m.Run()
+
+ // Note: m.Run currently prints the final "PASS" line, so if any race is
+ // reported here (after m.Run but before the process exits), it will print
+ // "PASS", then print the stack traces for the race, then exit with nonzero
+ // status.
+ //
+ // This is a somewhat fundamental race: because the race detector hooks into
+ // the runtime at a very low level, no matter where we put the printing it
+ // would be possible to report a race that occurs afterward. However, we could
+ // theoretically move the printing after TestMain, which would at least do a
+ // better job of diagnosing races in cleanup functions within TestMain itself.
}
func TestTempDirInCleanup(t *testing.T) {
t.Errorf("in non-test testing.Test() returned %q, want %q", s, "false")
}
}
+
+// runTest runs a helper test with -test.v, ignoring its exit status.
+// runTest both logs and returns the test output.
+func runTest(t *testing.T, test string) []byte {
+ t.Helper()
+
+ testenv.MustHaveExec(t)
+
+ exe, err := os.Executable()
+ if err != nil {
+ t.Skipf("can't find test executable: %v", err)
+ }
+
+ cmd := testenv.Command(t, exe, "-test.run=^"+test+"$", "-test.bench="+test, "-test.v", "-test.parallel=2", "-test.benchtime=2x")
+ cmd = testenv.CleanCmdEnv(cmd)
+ cmd.Env = append(cmd.Env, "GO_WANT_HELPER_PROCESS=1")
+ out, err := cmd.CombinedOutput()
+ t.Logf("%v: %v\n%s", cmd, err, out)
+
+ return out
+}
+
+// doRace provokes a data race that generates a race detector report if run
+// under the race detector and is otherwise benign.
+func doRace() {
+ var x int
+ c1 := make(chan bool)
+ go func() {
+ x = 1 // racy write
+ c1 <- true
+ }()
+ _ = x // racy read
+ <-c1
+}
+
+func TestRaceReports(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ // Generate a race detector report in a sub test.
+ t.Run("Sub", func(t *testing.T) {
+ doRace()
+ })
+ return
+ }
+
+ out := runTest(t, "TestRaceReports")
+
+ // We should see at most one race detector report.
+ c := bytes.Count(out, []byte("race detected"))
+ want := 0
+ if race.Enabled {
+ want = 1
+ }
+ if c != want {
+ t.Errorf("got %d race reports, want %d", c, want)
+ }
+}
+
+// Issue #60083. This used to fail on the race builder.
+func TestRaceName(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ doRace()
+ return
+ }
+
+ out := runTest(t, "TestRaceName")
+
+ if regexp.MustCompile(`=== NAME\s*$`).Match(out) {
+ t.Errorf("incorrectly reported test with no name")
+ }
+}
+
+func TestRaceSubReports(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ t.Parallel()
+ c1 := make(chan bool, 1)
+ t.Run("sub", func(t *testing.T) {
+ t.Run("subsub1", func(t *testing.T) {
+ t.Parallel()
+ doRace()
+ c1 <- true
+ })
+ t.Run("subsub2", func(t *testing.T) {
+ t.Parallel()
+ doRace()
+ <-c1
+ })
+ })
+ doRace()
+ return
+ }
+
+ out := runTest(t, "TestRaceSubReports")
+
+ // There should be three race reports: one for each subtest, and one for the
+ // race after the subtests complete. Note that because the subtests run in
+ // parallel, the race stacks may both be printed in with one or the other
+ // test's logs.
+ cReport := bytes.Count(out, []byte("race detected during execution of test"))
+ wantReport := 0
+ if race.Enabled {
+ wantReport = 3
+ }
+ if cReport != wantReport {
+ t.Errorf("got %d race reports, want %d", cReport, wantReport)
+ }
+
+ // Regardless of when the stacks are printed, we expect each subtest to be
+ // marked as failed, and that failure should propagate up to the parents.
+ cFail := bytes.Count(out, []byte("--- FAIL:"))
+ wantFail := 0
+ if race.Enabled {
+ wantFail = 4
+ }
+ if cFail != wantFail {
+ t.Errorf(`got %d "--- FAIL:" lines, want %d`, cReport, wantReport)
+ }
+}
+
+func TestRaceInCleanup(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ t.Cleanup(doRace)
+ t.Parallel()
+ t.Run("sub", func(t *testing.T) {
+ t.Parallel()
+ // No race should be reported for sub.
+ })
+ return
+ }
+
+ out := runTest(t, "TestRaceInCleanup")
+
+ // There should be one race report, for the parent test only.
+ cReport := bytes.Count(out, []byte("race detected during execution of test"))
+ wantReport := 0
+ if race.Enabled {
+ wantReport = 1
+ }
+ if cReport != wantReport {
+ t.Errorf("got %d race reports, want %d", cReport, wantReport)
+ }
+
+ // Only the parent test should be marked as failed.
+ // (The subtest does not race, and should pass.)
+ cFail := bytes.Count(out, []byte("--- FAIL:"))
+ wantFail := 0
+ if race.Enabled {
+ wantFail = 1
+ }
+ if cFail != wantFail {
+ t.Errorf(`got %d "--- FAIL:" lines, want %d`, cReport, wantReport)
+ }
+}
+
+func TestDeepSubtestRace(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ t.Run("sub", func(t *testing.T) {
+ t.Run("subsub", func(t *testing.T) {
+ t.Run("subsubsub", func(t *testing.T) {
+ doRace()
+ })
+ })
+ doRace()
+ })
+ return
+ }
+
+ out := runTest(t, "TestDeepSubtestRace")
+
+ c := bytes.Count(out, []byte("race detected during execution of test"))
+ want := 0
+ // There should be two race reports.
+ if race.Enabled {
+ want = 2
+ }
+ if c != want {
+ t.Errorf("got %d race reports, want %d", c, want)
+ }
+}
+
+func TestRaceDuringParallelFailsAllSubtests(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ var ready sync.WaitGroup
+ ready.Add(2)
+ done := make(chan struct{})
+ go func() {
+ ready.Wait()
+ doRace() // This race happens while both subtests are running.
+ close(done)
+ }()
+
+ t.Run("sub", func(t *testing.T) {
+ t.Run("subsub1", func(t *testing.T) {
+ t.Parallel()
+ ready.Done()
+ <-done
+ })
+ t.Run("subsub2", func(t *testing.T) {
+ t.Parallel()
+ ready.Done()
+ <-done
+ })
+ })
+
+ return
+ }
+
+ out := runTest(t, "TestRaceDuringParallelFailsAllSubtests")
+
+ c := bytes.Count(out, []byte("race detected during execution of test"))
+ want := 0
+ // Each subtest should report the race independently.
+ if race.Enabled {
+ want = 2
+ }
+ if c != want {
+ t.Errorf("got %d race reports, want %d", c, want)
+ }
+}
+
+func TestRaceBeforeParallel(t *testing.T) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") == "1" {
+ t.Run("sub", func(t *testing.T) {
+ doRace()
+ t.Parallel()
+ })
+ return
+ }
+
+ out := runTest(t, "TestRaceBeforeParallel")
+
+ c := bytes.Count(out, []byte("race detected during execution of test"))
+ want := 0
+ // We should see one race detector report.
+ if race.Enabled {
+ want = 1
+ }
+ if c != want {
+ t.Errorf("got %d race reports, want %d", c, want)
+ }
+}
+
+func TestRaceBeforeTests(t *testing.T) {
+ testenv.MustHaveExec(t)
+
+ exe, err := os.Executable()
+ if err != nil {
+ t.Skipf("can't find test executable: %v", err)
+ }
+
+ cmd := testenv.Command(t, exe, "-test.run=^$")
+ cmd = testenv.CleanCmdEnv(cmd)
+ cmd.Env = append(cmd.Env, "GO_WANT_RACE_BEFORE_TESTS=1")
+ out, _ := cmd.CombinedOutput()
+ t.Logf("%s", out)
+
+ c := bytes.Count(out, []byte("race detected outside of test execution"))
+
+ want := 0
+ if race.Enabled {
+ want = 1
+ }
+ if c != want {
+ t.Errorf("got %d race reports; want %d", c, want)
+ }
+}
+
+func TestBenchmarkRace(t *testing.T) {
+ out := runTest(t, "BenchmarkRacy")
+ c := bytes.Count(out, []byte("race detected during execution of test"))
+
+ want := 0
+ // We should see one race detector report.
+ if race.Enabled {
+ want = 1
+ }
+ if c != want {
+ t.Errorf("got %d race reports; want %d", c, want)
+ }
+}
+
+func BenchmarkRacy(b *testing.B) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") != "1" {
+ b.Skipf("skipping intentionally-racy benchmark")
+ }
+ for i := 0; i < b.N; i++ {
+ doRace()
+ }
+}
+
+func TestBenchmarkSubRace(t *testing.T) {
+ out := runTest(t, "BenchmarkSubRacy")
+ c := bytes.Count(out, []byte("race detected during execution of test"))
+
+ want := 0
+ // We should see two race detector reports:
+ // one in the sub-bencmark, and one in the parent afterward.
+ if race.Enabled {
+ want = 2
+ }
+ if c != want {
+ t.Errorf("got %d race reports; want %d", c, want)
+ }
+}
+
+func BenchmarkSubRacy(b *testing.B) {
+ if os.Getenv("GO_WANT_HELPER_PROCESS") != "1" {
+ b.Skipf("skipping intentionally-racy benchmark")
+ }
+
+ b.Run("non-racy", func(b *testing.B) {
+ tot := 0
+ for i := 0; i < b.N; i++ {
+ tot++
+ }
+ _ = tot
+ })
+
+ b.Run("racy", func(b *testing.B) {
+ for i := 0; i < b.N; i++ {
+ doRace()
+ }
+ })
+
+ doRace() // should be reported separately
+}