testing: Deferred functions run before parallel subtests are executed

[adamwg]

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

go version go1.7.3 darwin/amd64

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/awg/code/golang"
GORACE=""
GOROOT="/usr/local/Cellar/go/1.7.3/libexec"
GOTOOLDIR="/usr/local/Cellar/go/1.7.3/libexec/pkg/tool/darwin_amd64"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/py/0t98br4x7ys6byx0d284gcn80000gn/T/go-build516232238=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"

What did you do?

Ran the following test:

package testbug

import "testing"

func TestBug(t *testing.T) {
	asdf := 1337
	defer func() {
		asdf = 7331
	}()

	t.Run("asdf", func(t *testing.T) {
		t.Parallel()
		if asdf != 1337 {
			t.Fatalf("wanted 1337, got %d\n", asdf)
		}
	})
}

What did you expect to see?

The test should pass, as according to the documentation t.Run should block until all parallel subtests are completed, and the deferred function should run only after t.Run returns.

What did you see instead?

The test fails:

% go test -v .
=== RUN   TestBug
=== RUN   TestBug/asdf
--- FAIL: TestBug (0.00s)
    --- FAIL: TestBug/asdf (0.00s)
        foo_test.go:14: wanted 1337, got 7331
FAIL
exit status 1
FAIL    github.com/adamwg/testbug       0.007s

[mrjrieke]

Interesting test. Not sure it's a bug however. Depends on the definition of Parallel function and what sort of contract or agreement it has with the compiler.

[adamwg]

Note that this issue isn't actually limited to deferred functions. Any code after the parallel subtests runs before they do:

package testbug

import "testing"

func TestBug(t *testing.T) {
    asdf := 1337

    t.Run("asdf", func(t *testing.T) {
        t.Parallel()
        if asdf != 1337 {
            t.Fatalf("wanted 1337, got %d\n", asdf)
        }
    })

    asdf = 7331
}

% go test -v .
=== RUN   TestBug
=== RUN   TestBug/asdf
--- FAIL: TestBug (0.00s)
    --- FAIL: TestBug/asdf (0.00s)
        foo_test.go:11: wanted 1337, got 7331
FAIL
exit status 1
FAIL    github.com/adamwg/testbug       0.007s

[0xmohit]

The following works:

package testbug

import "testing"

func TestBug(t *testing.T) {
        asdf := 1337
        defer func() {
                asdf = 7331
        }()

        t.Run("group", func(t *testing.T) {
                t.Run("asdf", func(t *testing.T) {
                        t.Parallel()
                        if asdf != 1337 {
                                t.Fatalf("wanted 1337, got %d\n", asdf)
                        }
                })
        })
}

=== RUN   TestBug
=== RUN   TestBug/group
=== RUN   TestBug/group/asdf
--- PASS: TestBug (0.00s)
    --- PASS: TestBug/group (0.00s)
        --- PASS: TestBug/group/asdf (0.00s)
        b_test.go:19: done
PASS
ok      command-line-arguments  0.002s

(Adapted from the example in "Cleaning up after a group of parallel tests" in the blog.)

[adamwg]

@0xmohit Thanks, I can do that as a workaround.

However, based on the documentation (https://golang.org/pkg/testing/#T.Run) it's not clear that's necessary. I'd suggest either this should be fixed, or the documentation should be updated to make it clear that a call to t.Run does not block if t.Parallel is used in its test function.

[rsc]

This is working correctly.

The docs for t.Run say:

// Run runs f as a subtest of t called name. It reports whether f succeeded.
// Run will block until all its parallel subtests have completed.

In this code:

    t.Run("asdf", func(t *testing.T) {
        t.Parallel()
        if asdf != 1337 {
            t.Fatalf("wanted 1337, got %d\n", asdf)
        }
    })

t.Parallel is making the t.Run itself a parallel subtest of TestBug. There is no parallel subtest of the t.Run subtest. TestBug will not complete until the parallel test completes. But TestBug's body has to finish because that is what triggers running the parallel tests in the first place.

In this code:

        t.Run("group", func(t *testing.T) {
                t.Run("asdf", func(t *testing.T) {
                        t.Parallel()
                        if asdf != 1337 {
                                t.Fatalf("wanted 1337, got %d\n", asdf)
                        }
                })
        })

The group has one parallel subtest, asdf. Once the group's body returns, the parallel subtests are allowed to run in parallel (there's only one so that's not saying much), and once the parallel subtest finishes, t.Run("group"...) returns.