testing: deferred func runs before parallel subtest #22993
Description
Also, Run's result was wrong.
What did you do?
I deferred a function in a package-scope test, then ran a parallel subtest that assumed the deferred function would run after it completes, but this wasn't the case, and Run returned true when the subtest failed.
Basically, this:
func TestFoo(t *testing.T) {
defer bar() // Runs before baz
var passed = t.Run("subtest", func(t *testing.T) {
t.Parallel()
baz() // Runs after bar
t.Fail()
} // Passed is true
// ...
}It doesn't matter whether the package-scope test is parallel.
A full example: https://play.golang.org/p/pMsKhRvjiW. Note that you'll have to run it locally.
The documentation for testing.T.Run says:
func (t *T) Run(name string, f func(t *T)) bool
Run runs f as a subtest of t called name. It reports whether f succeeded.
Run runs f in a separate goroutine and will block until all its parallel
subtests have completed.
Run may be called simultaneously from multiple goroutines, but all such
calls must return before the outer test function for t returns.
This seems to say that Run always returns an accurate status of the subtest, even if it's parallel, which means the subtest must finish before the Run call completes, and thus before the parent test returns, after which its deferred functions run, but I'm seeing such a deferred function run first. The discussion in https://golang.org/pkg/testing/#hdr-Subtests_and_Sub_benchmarks similarly indicates to me this is incorrect behavior, specifically the paragraphs starting with "Subtests can also be used to control parallelism" and "Run does not return until parallel subtests have completed".
The documentation for testing.T.Parallel says:
func (t *T) Parallel()
Parallel signals that this test is to be run in parallel with (and only
with) other parallel tests. When a test is run multiple times due to use of
-test.count or -test.cpu, multiple instances of a single test never run in
parallel with each other.
This doesn't seem to augment Run's documentation's guarantees, but I'm not sure.
I feel like I must be missing something obvious, but a colleague agreed with my interpretation.
What did you expect to see?
$ go test -v
=== RUN TestFoo
=== RUN TestFoo/sub
--- PASS: TestFoo (0.00s)
t_test.go:34: passed: actual true, expected true
--- PASS: TestFoo/sub (0.00s)
PASS
ok t 0.036s
What did you see instead?
$ go test -v
=== RUN TestFoo
=== RUN TestFoo/sub
--- FAIL: TestFoo (0.00s)
t_test.go:34: passed: actual true, expected true
--- FAIL: TestFoo/sub (0.10s)
t_test.go:24: Get http://127.0.0.1:61311: dial tcp 127.0.0.1:61311: getsockopt: connection refused
t_test.go:28: response: actual nil, expected not nil
FAIL
exit status 1
FAIL t 0.141s
System details
go version go1.9.2 darwin/amd64
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/willfaught/Developer/go"
GORACE=""
GOROOT="/usr/local/Cellar/go/1.9.2/libexec"
GOTOOLDIR="/usr/local/Cellar/go/1.9.2/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/_1/ggvd2t1x7hz_185crsb36zlr0000gp/T/go-build590837635=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOROOT/bin/go version: go version go1.9.2 darwin/amd64
GOROOT/bin/go tool compile -V: compile version go1.9.2
uname -v: Darwin Kernel Version 17.2.0: Fri Sep 29 18:27:05 PDT 2017; root:xnu-4570.20.62~3/RELEASE_X86_64
ProductName: Mac OS X
ProductVersion: 10.13.1
BuildVersion: 17B1003
lldb --version: lldb-900.0.57
Swift-4.0