cmd/test2json: tests that panic are marked as passing

[zolotov]

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

$ go version
go version go1.15beta1 darwin/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
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/zolotov/Library/Caches/go-build"
GOENV="/Users/zolotov/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/zolotov/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/zolotov/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/Users/zolotov/go/go1.15beta1"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/Users/zolotov/go/go1.15beta1/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
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=/var/folders/pg/md95lhn52rj2x8jtfdr_d1cc0000gp/T/go-build033989892=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

1. Compile test with go test -c

package main

import (
	"testing"
)

func TestColor(t *testing.T) {
	panic(123)
}

2. run it with test2json tool

3. get the output like that

/Users/zolotov/go/go1.15beta1/bin/go tool test2json -t /private/var/folders/pg/md95lhn52rj2x8jtfdr_d1cc0000gp/T/___1TestColor_in_awesomeProject21                                       
{"Time":"2020-07-06T23:35:36.37331+03:00","Action":"output","Test":"TestColor","Output":"--- FAIL: TestColor (0.00s)\n"}
{"Time":"2020-07-06T23:35:36.375884+03:00","Action":"output","Test":"TestColor","Output":"panic: 123 [recovered]\n"}
{"Time":"2020-07-06T23:35:36.375897+03:00","Action":"output","Test":"TestColor","Output":"\tpanic: 123\n"}
{"Time":"2020-07-06T23:35:36.375906+03:00","Action":"output","Test":"TestColor","Output":"\n"}
{"Time":"2020-07-06T23:35:36.375911+03:00","Action":"output","Test":"TestColor","Output":"goroutine 21 [running]:\n"}
{"Time":"2020-07-06T23:35:36.375917+03:00","Action":"output","Test":"TestColor","Output":"testing.tRunner.func1.1(0x411d400, 0x416e6c8)\n"}
{"Time":"2020-07-06T23:35:36.375923+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/go1.15beta1/src/testing/testing.go:1057 +0x30d\n"}
{"Time":"2020-07-06T23:35:36.375934+03:00","Action":"output","Test":"TestColor","Output":"testing.tRunner.func1(0xc000082900)\n"}
{"Time":"2020-07-06T23:35:36.375938+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/go1.15beta1/src/testing/testing.go:1060 +0x41a\n"}
{"Time":"2020-07-06T23:35:36.375943+03:00","Action":"output","Test":"TestColor","Output":"panic(0x411d400, 0x416e6c8)\n"}
{"Time":"2020-07-06T23:35:36.375947+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/go1.15beta1/src/runtime/panic.go:969 +0x175\n"}
{"Time":"2020-07-06T23:35:36.375952+03:00","Action":"output","Test":"TestColor","Output":"awesomeProject21.TestColor(0xc000082900)\n"}
{"Time":"2020-07-06T23:35:36.376078+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/src/awesomeProject21/go_test.go:9 +0x39\n"}
{"Time":"2020-07-06T23:35:36.376086+03:00","Action":"output","Test":"TestColor","Output":"testing.tRunner(0xc000082900, 0x414f870)\n"}
{"Time":"2020-07-06T23:35:36.376089+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/go1.15beta1/src/testing/testing.go:1108 +0xef\n"}
{"Time":"2020-07-06T23:35:36.376092+03:00","Action":"output","Test":"TestColor","Output":"created by testing.(*T).Run\n"}
{"Time":"2020-07-06T23:35:36.376095+03:00","Action":"output","Test":"TestColor","Output":"\t/Users/zolotov/go/go1.15beta1/src/testing/testing.go:1159 +0x386\n"}
{"Time":"2020-07-06T23:35:36.376305+03:00","Action":"pass","Test":"TestColor","Elapsed":0.07}

What did you expect to see?

The last event will be fail

What did you see instead?

The last event is pass

[dmitshur]

/cc @jayconrod @bcmills @matloob

[bcmills]

CC @eliben @mvdan (by way of #31969)

Perhaps cmd/test2json with an explicit command argument should check the exit code of the binary; but then it still wouldn't be able to correctly annotate test logs supplied via standard input. The log of a test binary is fundamentally not sufficient to tell whether it passed or failed.

Since test functions that call os.Exit(0) should be exceedingly rare anyway (#29062), I agree with @mvdan's comment in #31969 (comment) that we should interpret a not-affirmatively-passing test as a failure rather than a success.

[dnephin]

This issue sounds related to #38382

I agree with @mvdan's comment in #31969 (comment) that we should interpret a not-affirmatively-passing test as a failure rather than a success.

I had to write that logic in gotestsum to handle the case of missing Action=fail events. It would be great if this could be handled by test2json or go test.

[bcmills]

@gopherbot, please backport to Go 1.15. This seems like a significant regression.

[gopherbot]

Backport issue(s) opened: #40805 (for 1.15).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

[gopherbot]

Change https://golang.org/cl/248624 mentions this issue: cmd/test2json: do not emit a final Action if the result is not known

[gopherbot]

Change https://golang.org/cl/248725 mentions this issue: [release-branch.go1.15] cmd/test2json: do not emit a final Action if the result is not known