Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

testing: misleading error message when a parallel Cleanup function calls runtime.Goexit #48502

Closed
bcmills opened this issue Sep 20, 2021 · 3 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@bcmills
Copy link
Contributor

bcmills commented Sep 20, 2021

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

$ go version
go version devel go1.18-a83a55873 Mon Sep 20 00:13:47 2021 +0000 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
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/usr/local/google/home/bcmills/.cache/go-build"
GOENV="/usr/local/google/home/bcmills/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/tmp/tmp.ZsmnxrVJrd/.gopath/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/tmp/tmp.ZsmnxrVJrd/.gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/google/home/bcmills/sdk/gotip"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/google/home/bcmills/sdk/gotip/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="devel go1.18-a83a55873 Mon Sep 20 00:13:47 2021 +0000"
GCCGO="/usr/local/google/home/bcmills/bin/gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="c++"
CGO_ENABLED="1"
GOMOD="/tmp/tmp.ZsmnxrVJrd/go.mod"
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 -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build743201453=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Run this test (https://play.golang.org/p/9Nn760Qo2Hc):

func TestGoexitInCleanupAfterPanic(t *testing.T) {
	t.Cleanup(func() {
		runtime.Goexit()
	})
	t.Parallel()
	panic("boom?")
}

What did you expect to see?

Something like the error output for https://play.golang.org/p/Pt1mKg_vfcc:

=== RUN   TestGoexitInCleanupAfterPanic
--- FAIL: TestGoexitInCleanupAfterPanic (0.00s)
panic: boom?
	panic: test executed panic(nil) or runtime.Goexit

goroutine 34 [running]:
testing.tRunner.func1.2({0x4b8a80, 0xc00010a290})
	/usr/local/go-faketime/src/testing/testing.go:1209 +0x24e
testing.tRunner.func1()
	/usr/local/go-faketime/src/testing/testing.go:1212 +0x218
runtime.Goexit()
	/usr/local/go-faketime/src/runtime/panic.go:642 +0x187
main.TestGoexitInCleanupAfterPanic.func1()
	/tmp/sandbox3322527438/prog.go:10 +0x17
testing.(*common).Cleanup.func1()
	/usr/local/go-faketime/src/testing/testing.go:912 +0x11f
testing.(*common).runCleanup(0xc0001109c0, 0x0)
	/usr/local/go-faketime/src/testing/testing.go:1049 +0x95
testing.tRunner.func2()
	/usr/local/go-faketime/src/testing/testing.go:1253 +0x29
panic({0x4b6460, 0x4ee0b0})
	/usr/local/go-faketime/src/runtime/panic.go:1038 +0x215
main.TestGoexitInCleanupAfterPanic(0x0)
	/tmp/sandbox3322527438/prog.go:12 +0x38
testing.tRunner(0xc0001109c0, 0x4d4cc0)
	/usr/local/go-faketime/src/testing/testing.go:1259 +0x102
created by testing.(*T).Run
	/usr/local/go-faketime/src/testing/testing.go:1306 +0x35a

What did you see instead?

=== RUN   TestGoexitInCleanupAfterPanic
=== PAUSE TestGoexitInCleanupAfterPanic
=== CONT  TestGoexitInCleanupAfterPanic
    testing.go:1169: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
--- FAIL: TestGoexitInCleanupAfterPanic (0.00s)
FAIL

I found this corner case while re-reviewing CL 256098 in order to understand some code in CL 348469.

CC @changkun @odeke-em @jayconrod

@bcmills bcmills added this to the Backlog milestone Sep 20, 2021
@bcmills bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 20, 2021
@changkun
Copy link
Member

After a year of sending CL 256098, and a lot newly merged CLs in between, I found the current testing package extremely hard to work on for those edge cases.

The current tRunner based implementation collaboration with mutexes is also not very convenient to collect information from parallel tests.

Not yet entirely sure how we arrived on today's status, but if it is possible to rework the entire package to use a producer-consumer pattern where tests are fan-out distributed to multiple runners, having a centralized error channel to collect all those panics (even logs) for parallel tests, then cache and read them back when all tests are scheduled and executed, the implementation will be much easier to read and work on.

If the newly added fuzzing feature is still producing major updates for the testing package, it would be an ideal time slot for the rework.

@bcmills
Copy link
Contributor Author

bcmills commented Sep 21, 2021

Agreed — the testing package is certainly in need of some refactoring.

(I don't think I would be inclined to specifically fan out to runners, but I would certainly like to replace the ad-hoc mutexes and channels with something more holistic.)

@gopherbot
Copy link

Change https://golang.org/cl/352350 mentions this issue: testing: fix error message when a parallel Cleanup calls runtime.Goexit

@golang golang locked and limited conversation to collaborators Nov 14, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

3 participants