testing: odd interaction between -json flag and TestMain

[eliben]

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

$ go version
go version go1.12 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output

$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/usr/local/google/home/eliben/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/usr/local/google/home/eliben/go"
GOPROXY="https://proxy.golang.org"
GORACE=""
GOROOT="/usr/lib/google-golang"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/google-golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build529164426=/tmp/go-build -gno-record-gcc-switches"

What did you do?

package main

import (
	"fmt"
	"os"
	"testing"
)

func TestJoe(t *testing.T) {
	fmt.Println("from joe")
}

func TestMain(m *testing.M) {
	if len(os.Getenv("XYZ")) > 0 {
		return
	}
	fmt.Println("before run")
	s := m.Run()
	fmt.Println("after run")
	os.Exit(s)
}

What did you expect to see?

When running go test with this file, the test passes. It also passes with go test -json. However, if I tickle the early return in TestMain:

$ XYZ=2 go test -json
{"Time":"2019-05-10T09:33:09.534255206-07:00","Action":"output","Package":"_testing/testmain","Output":"ok  \t_testing/testmain\t0.019s\n"}
{"Time":"2019-05-10T09:33:09.534473515-07:00","Action":"fail","Package":"_testing/testmain","Elapsed":0.019}

Note the fail status in the last line. The exit code of this go test -json run is 0, even though it (wrongly) reported failure. Regularly running go test here passes, as expected.

[andybons]

@mpvl @josharian

[hanleym]

This seems to happen when TestMain returns without m.Run() being called; regardless of os.Exit().

[ryanbrainard]

I'm experiencing this same behavior with test2json. I'm assuming they share the same code path, so that makes sense.

To add to what is above, it does not matter if you return from TestMain() or os.Exit(0) from TestMain(), they both exhibit this behavior.

Here is my repro for test2json:

package dummy

import (
	"os"
	"testing"
)

func TestMain(m *testing.M) {
	os.Exit(0)
	// os.Exit(m.Run())
}

func TestDummy(t *testing.T) {
}

Run tests:

$ go test -c -o test-exec
$ go tool test2json -t ./test-exec
{"Time":"2019-08-27T10:10:53.931641+09:00","Action":"fail","Elapsed":0.005}

Toggling the commented lines in TestMain() results in:

$ go test -c -o test-exec         
$ go tool test2json -t ./test-exec
{"Time":"2019-08-27T10:11:51.007087+09:00","Action":"output","Output":"PASS\n"}
{"Time":"2019-08-27T10:11:51.007417+09:00","Action":"pass","Elapsed":0.006}

On a related note, when there are no tests and m.Run() is called, the test2json shows "passed" even though the docs state "skip - the test was skipped or the package contained no tests"

[gopherbot]

Change https://golang.org/cl/192104 mentions this issue: test2json: default to "pass" when the test doesn't report failures

[eliben]

I believe I understand what's going on. The test commands uses a converter from test2json to filter its stdout. test2json looks for PASS lines to mark a "pass" and FAIL lines to mark a "fail", but if no such lines are encountered in the stdout of the running test, it currently defaults to "fail" -- see

go/src/cmd/internal/test2json/test2json.go

Line 287 in 7254cfc

e := &event{Action: "fail"}

I sent https://golang.org/cl/192104 to change this to "pass", and all tests pass except one where the current behavior is explicitly assumed.

Trying to think of any bad side effects of this... In general, the behavior of test2json is hereby aligned to go test, which will take a "no tests run" as a passing event.

Note: this change makes the behavior similar to running in a directory with no tests, where test2json currently reports a "pass".

[mvdan]

I'm not positive that this is the right fix. In #29062, the fix is to make go test fail if the test binary didn't print PASS, so I think we should apply the same fix to test2json.

[eliben]

@mvdan the main complaint in this issue was that -json has different semantics from no-json, and the CL aligns them.

If the original semantics of no-json are reversed, then the CL should be reverted.

I'll comment on #29062

[mvdan]

Yup. My suggestion would be to reopen this issue to revert its CL, once the other issue is fixed.

[gopherbot]

Change https://golang.org/cl/222243 mentions this issue: cmd/go: make go test -json report failures for panicking/exiting tests

[gopherbot]

Change https://golang.org/cl/222658 mentions this issue: [release-branch.go1.14] cmd/go: make go test -json report failures for panicking/exiting tests