cmd/go, testing: TB.Failed does not report race failures

[tamird]

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (go version)?

go version go1.8 darwin/amd64

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/tamird/src/go"
GORACE=""
GOROOT="/Users/tamird/src/go1.8"
GOTOOLDIR="/Users/tamird/src/go1.8/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/lf/1_qqs3815tzgkhtrbrjs913m0000gn/T/go-build904117806=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

main_test.go:

package main

import "testing"

func TestRace(t *testing.T) {
	t.Run("", func(t *testing.T) {
		defer func() {
			if !t.Failed() {
				t.Errorf("subtest did not fail")
			}
		}()
		for i := 0; i < 10; i++ {
			c := make(chan int)
			x := 1
			go func() {
				x = 2
				c <- 1
			}()
			x = 3
			<-c
		}
	})
	if !t.Failed() {
		t.Errorf("test did not fail")
	}
}

What did you expect to see?

==================
WARNING: DATA RACE
Write at 0x00c420070df8 by goroutine 8:
  github.com/cockroachdb/cockroach/foo.TestRace.func1.2()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:16 +0x3b

Previous write at 0x00c420070df8 by goroutine 7:
  github.com/cockroachdb/cockroach/foo.TestRace.func1()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:19 +0xf6
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107

Goroutine 8 (running) created at:
  github.com/cockroachdb/cockroach/foo.TestRace.func1()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:18 +0xe5
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /Users/tamird/src/go1.8/src/testing/testing.go:697 +0x543
  github.com/cockroachdb/cockroach/foo.TestRace()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:22 +0x5a
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107
==================
--- FAIL: TestRace (0.00s)
    --- FAIL: TestRace/#00 (0.00s)
    	testing.go:610: race detected during execution of test
	testing.go:610: race detected during execution of test
FAIL
FAIL	github.com/cockroachdb/cockroach/foo	0.021s

What did you see instead?

==================
WARNING: DATA RACE
Write at 0x00c42006edf8 by goroutine 8:
  github.com/cockroachdb/cockroach/foo.TestRace.func1.2()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:16 +0x3b

Previous write at 0x00c42006edf8 by goroutine 7:
  github.com/cockroachdb/cockroach/foo.TestRace.func1()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:19 +0xf6
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107

Goroutine 8 (running) created at:
  github.com/cockroachdb/cockroach/foo.TestRace.func1()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:18 +0xe5
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /Users/tamird/src/go1.8/src/testing/testing.go:697 +0x543
  github.com/cockroachdb/cockroach/foo.TestRace()
      /Users/tamird/src/go/src/github.com/cockroachdb/cockroach/foo/main_test.go:22 +0x5a
  testing.tRunner()
      /Users/tamird/src/go1.8/src/testing/testing.go:657 +0x107
==================
--- FAIL: TestRace (0.00s)
    --- FAIL: TestRace/#00 (0.00s)
    	main_test.go:9: subtest did not fail
    	testing.go:610: race detected during execution of test
	testing.go:610: race detected during execution of test
FAIL
FAIL	github.com/cockroachdb/cockroach/foo	0.015s

Note the presence of main_test.go:9: subtest did not fail. We're running into this issue in CockroachDB, where we have logging redirection taking place for the duration of the test; if the test is not observed to have failed at the end of the run, the logs are cleaned up. As the snippet above demonstrates, it's not currently possible for a test to observe its own race-related failure, so we end up losing our logs. The CockroachDB issue is cockroachdb/cockroach#14563.

Related to #15972.

cc @dvyukov @rsc

[dvyukov]

Probably need to make t.Failed look at race.Errors().

[cespare]

I have a WIP CL. I think the fix is easy but writing a test requires a certain amount of cleverness I'm not sure I possess. I'll take another look later (but testing ideas on the CL are appreciated).

[gopherbot]

CL https://golang.org/cl/39890 mentions this issue.

[gopherbot]

Change https://golang.org/cl/54050 mentions this issue: testing: don't fail all tests after racy test failure

[gopherbot]

Change https://golang.org/cl/57151 mentions this issue: [release-branch.go1.9] testing: don't fail all tests after racy test failure