go: cmd/go: tests that panic or exit are marked as passing when -json flag is used

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

$ go version
go version go1.14 windows/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
set GO111MODULE=on
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\florin\AppData\Local\go-build
set GOENV=C:\Users\florin\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=D:\go
set GOPRIVATE=
set GOPROXY=direct
set GOROOT=C:\go-distros\go1.14
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\go-distros\go1.14\pkg\tool\windows_amd64
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=D:\GoLandProjects\awesomeProject26\go.mod
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\Users\florin\AppData\Local\Temp\go-build954171622=/tmp/go-build -gno-record-gcc-switches

What did you do?

take the code from here: https://play.golang.org/p/sM_HbzDzmXn
run the following commands:

go test -c -coverpkg=./... -covermode=atomic -o mytests.exe awesomeProject26
go tool test2json -t ./mytests.exe -test.v -test.coverprofile cov.out

What did you expect to see?

I would expect to see that TestName2 fails since there’s a panic there. See the output here: https://play.golang.org/p/-9xQPOYa5iN

What did you see instead?

Test is marked as pass in the resulting json:

{
	"Time":"2020-02-28T15:26:08.7281772+02:00",
	"Action":"pass",
	"Test":"TestName2",
	"Elapsed":0.286
}

The test position doesn’t seem to matter, if it’s the first, the last, or in the middle of the test suite.

This is confirmed to happen both on Windows and Ubuntu.

About this issue

Original URL
State: closed
Created 4 years ago
Reactions: 3
Comments: 22 (14 by maintainers)

Commits related to this issue

[release-branch.go1.14] cmd/go: make go test -json report failures for panicking/exiting tests 'go test -json' should report that a test failed if the test binary did not exit normally with status 0.... — committed to golang/go by deleted user 4 years ago

Most upvoted comments

@jayconrod @bcmills the problem is still reproducible while running test2json directly. The output of Go 1.15 beta1 test run:

package main

import (
	"testing"
)

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

/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}

Notice the last event, it claims that TestColor is passed.

zolotov on Jul 6, 2020

Given the reliance of test2json on -test.v, this is likely a side-effect of #24929.

bcmills on Mar 4, 2020

Thanks for the reply.

grasparv on Mar 10, 2020

Should not all output be JSON if you run with -json?

Probably yes. That’s what #35169 is about.

This issue was about a specific regression in the -json output. Since it’s a regression, it’s been backported for 1.14.1.

go test has not produced JSON output for build failures before, so that’s being considered separately as a feature request.

jayconrod on Mar 10, 2020

I think this was triggered by CL 192104. test2json started failing open instead of failing closed.

If the test binary fails for any reason (exits non-zero, fails to run), go test is supposed to add a message to stdout. But test2json doesn’t understand the message that go test writes.

Will have a CL soon.

jayconrod on Mar 5, 2020