testing: t.Cleanup should report non-helper caller information

[prashantv]

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

$ go version
go version go1.14.2 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="/home/prashant/.cache/go-build"
GOENV="/home/prashant/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/prashant/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/prashant/.gimme/versions/go1.14.2.linux.amd64"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/prashant/.gimme/versions/go1.14.2.linux.amd64/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-build997550945=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Used t.Cleanup and passed in t.Helper so that the original caller of the Cleanup function would be mentioned
https://play.golang.org/p/AzLAUWwuSGJ

What did you expect to see?

Some mention of the non-helper file:line that called a helper function that then used a cleanup.

E.g.,

=== RUN   TestFoo
    TestFoo: prog.go:6: Failed to create: foo
    TestFoo: prog.go:8: Failed to create: bar
    TestFoo: prog.go:6: Delete temporary file failed: bar
    TestFoo: prog.go:8: Delete temporary file failed: foo
--- FAIL: TestFoo (0.00s)

It may also want to mention cleanup from that line

=== RUN   TestFoo
    TestFoo: prog.go:6: Failed to create: foo
    TestFoo: prog.go:8: Failed to create: bar
    TestFoo: prog.go:6 (cleanup): Delete temporary file failed: bar
    TestFoo: prog.go:8 (cleanup): Delete temporary file failed: foo
--- FAIL: TestFoo (0.00s)

What did you see instead?

=== RUN   TestFoo
    TestFoo: prog.go:6: Failed to create: foo
    TestFoo: prog.go:8: Failed to create: bar
    TestFoo: testing.go:789: Delete temporary file failed: bar
    TestFoo: testing.go:789: Delete temporary file failed: foo
--- FAIL: TestFoo (0.00s)

Note, removing the t.Helper inside the cleanup results in the helper Create function showing up:

=== RUN   TestFoo
    TestFoo: prog.go:6: Failed to create: foo
    TestFoo: prog.go:8: Failed to create: bar
    TestFoo: prog.go:17: Delete temporary file failed: bar
    TestFoo: prog.go:17: Delete temporary file failed: foo
--- FAIL: TestFoo (0.00s)

Other Details

Only the testing library knows about which methods in the callstack have called t.Helper, so it's not possible for the helper function to track caller itself and report it in the Cleanup function. Ideally, at the point of Cleanup, the caller information is recorded, so it can be used for failures in cleanup.

[ianlancetaylor]

I think the suggestion here is: when Cleanup is called, record the caller, ignoring helper functions. Then, if a cleanup function calls t.Helper, and it calls t.Log, report the recorded caller rather than an unhelpful line in testing.go.

[mlowicki]

I'll take a look at this issue.

[gopherbot]

Change https://golang.org/cl/232237 mentions this issue: testing: Func passed to Cleanup reports Cleanup as caller