testing: Docs unclear what Cleanup does when called in a subtest.

[brackendawson]

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

$ go version
go version go1.14rc1 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="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
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 -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build584459223=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Ran t.Cleanup in a subtest:

package cleanup

import "testing"

func TestCleanup(t *testing.T) {
	t.Log("Start of test")
	t.Cleanup(func() {
		t.Log("Test Cleanup")
	})
	for _, test := range []string{"one", "two"} {
		t.Run("test", func(t *testing.T) {
			t.Log("Start of subtest", test)
			t.Cleanup(func() {
				name := test
				t.Log("Subtest", name, "cleanup")
			})
			t.Log("End of subtest", test)
		})
	}
	t.Log("End of test")
}

What did you expect to see?

I didn't know, from the docs I knew that a test function's cleanups run after the test and all subtests finish, but I don't know what happens when you register a cleanup function in a subtest.

The docs say: "Cleanup registers a function to be called when the test and all its subtests complete. Cleanup functions will be called in last added, first called order."

What did you see instead?

I learned that cleanup functions registered in subtests get run at the end of that subtest, but I don't know if this behaviour is intended or stable?

=== RUN   TestCleanup
    TestCleanup: cleanup_test.go:6: Start of test
=== RUN   TestCleanup/test
    TestCleanup/test: cleanup_test.go:12: Start of subtest one
    TestCleanup/test: cleanup_test.go:17: End of subtest one
    TestCleanup/test: cleanup_test.go:15: Subtest one cleanup
=== RUN   TestCleanup/test#01
    TestCleanup/test#01: cleanup_test.go:12: Start of subtest two
    TestCleanup/test#01: cleanup_test.go:17: End of subtest two
    TestCleanup/test#01: cleanup_test.go:15: Subtest two cleanup
    TestCleanup: cleanup_test.go:20: End of test
    TestCleanup: cleanup_test.go:8: Test Cleanup
--- PASS: TestCleanup (0.00s)
    --- PASS: TestCleanup/test (0.00s)
    --- PASS: TestCleanup/test#01 (0.00s)
PASS
ok      _/cleanup       0.004s

Could the docs be expanded to reflect the intention?

[toothrot]

/cc @rogpeppe who implemented this for #32111

[rogpeppe]

This is working exactly as designed. I'm not sure exactly how better to phrase the docs. A subtest is a test in itself even if it's a subtest too. Any suggestions for better phrasing?

[brackendawson]

I'm a fan of telling the reader the truth, though the current testing doc doesn't mention anywhere that a subtest is a test in itself, or explicitly say that it's T is a different instance of T. Maybe keeping it short is better, I only went down this line of though because of the line: "called when the test and all its subtests complete".

How about:
"Cleanup registers a function to be called when the test and all its subtests complete. Cleanup functions will be called in last added, first called order. Cleanup functions registered in a subtest are called when that subtest completes."

Likewise for B.Cleanup.

[seankhliao]

Closing as this was done with "Cleanup registers a function to be called when the test (or subtest) and all its subtests complete"