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

Jump to bottom

testing: t.Fatal does not fatal tests if defers do not complete #22989

Closed
zwass opened this issue Dec 4, 2017 · 3 comments
Closed

testing: t.Fatal does not fatal tests if defers do not complete #22989

zwass opened this issue Dec 4, 2017 · 3 comments
Labels
Documentation FrozenDueToAge
Milestone
Go1.10

Comments

@zwass
Copy link

zwass commented Dec 4, 2017

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

go version go1.9.2 darwin/amd64

Does this issue reproduce with the latest release?

Yes.

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/zwass/dev/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/4k/2q3ctn7d5_xb03_zsb3v6lgr0000gn/T/go-build085156185=/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"

What did you do?

test_test.go

package test

import (
	"sync"
	"testing"
	"time"
)

func TestTest(t *testing.T) {
	var m sync.Mutex
	defer m.Lock()
	go func() {
		for {
			time.Sleep(1 * time.Second)
		}
	}()

	m.Lock()
	t.Fatal("foobar")
}

What did you expect to see?

go test -v
=== RUN   TestTest
--- FAIL: TestTest (0.00s)
	test_test.go:19: foobar
FAIL
exit status 1
FAIL	test	0.007s

What did you see instead?

go test -v
=== RUN   TestTest
panic: test timed out after 10m 0s

goroutine 17 [running]:
testing.startAlarm.func1()
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:1145 +0xf9
created by time.goFunc
	/usr/local/Cellar/go/1.9.2/libexec/src/time/sleep.go:170 +0x44

goroutine 1 [chan receive]:
testing.(*T).Run(0xc420094000, 0x1135230, 0x8, 0x113d640, 0x10688b6)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:790 +0x2fc
testing.runTests.func1(0xc420094000)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:1004 +0x64
testing.tRunner(0xc420094000, 0xc420043de0)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:746 +0xd0
testing.runTests(0xc42000a060, 0x11db860, 0x1, 0x1, 0xc42004c3b0)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:1002 +0x2d8
testing.(*M).Run(0xc420043f18, 0xc420043f70)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:921 +0x111
main.main()
	test/_test/_testmain.go:44 +0xdb

goroutine 6 [semacquire]:
sync.runtime_SemacquireMutex(0xc4200140ec, 0xc420048e00)
	/usr/local/Cellar/go/1.9.2/libexec/src/runtime/sema.go:71 +0x3d
sync.(*Mutex).Lock(0xc4200140e8)
	/usr/local/Cellar/go/1.9.2/libexec/src/sync/mutex.go:134 +0xee
runtime.Goexit()
	/usr/local/Cellar/go/1.9.2/libexec/src/runtime/panic.go:366 +0x147
testing.(*common).FailNow(0xc4200940f0)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:544 +0x39
testing.(*common).Fatal(0xc4200940f0, 0xc420030788, 0x1, 0x1)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:582 +0x6f
test.TestTest(0xc4200940f0)
	/Users/zwass/dev/go/src/test/test_test.go:19 +0xdc
testing.tRunner(0xc4200940f0, 0x113d640)
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:746 +0xd0
created by testing.(*T).Run
	/usr/local/Cellar/go/1.9.2/libexec/src/testing/testing.go:789 +0x2de

goroutine 7 [sleep]:
time.Sleep(0x3b9aca00)
	/usr/local/Cellar/go/1.9.2/libexec/src/runtime/time.go:65 +0x130
test.TestTest.func1()
	/Users/zwass/dev/go/src/test/test_test.go:14 +0x2a
created by test.TestTest
	/Users/zwass/dev/go/src/test/test_test.go:12 +0x78
exit status 2
FAIL	test	600.010s

The above example is obviously broken, but this hanging behavior from the test runner causes quite a confusing experience when there are more subtle issues going on.

It's also worth noting that there is no way to determine from the dumped goroutines what is causing the hang.

From what I can tell, this is due to t.FailNow() using runtime.GoExit() which waits for defers to complete.

The docs for t.FailNow() say the following:

FailNow marks the function as having failed and stops its execution. Execution will continue at the next test or benchmark. FailNow must be called from the goroutine running the test or benchmark function, not from other goroutines created during the test. Calling FailNow does not stop those other goroutines.
@ianlancetaylor ianlancetaylor changed the title t.Fatal does not fatal tests if defers do not complete testing: t.Fatal does not fatal tests if defers do not complete Dec 5, 2017
@ianlancetaylor ianlancetaylor added this to the Go1.10 milestone Dec 5, 2017
@ianlancetaylor
Copy link
Contributor

I'm marking this as a documentation issue. If someone can figure out how to fix it reasonably, that's fine with me. But in practice I think we should just document this and move on.

@gopherbot
Copy link

Change https://golang.org/cl/83881 mentions this issue: testing: emphasize that Fatal/FailNow/etc run deferred calls

@rsc
Copy link
Contributor

rsc commented Dec 14, 2017

This is working as intended. You want those deferred calls to run and finish before the test is torn down. If one is buggy and blocks forever, well, sorry. Sent a CL.

@golang golang locked and limited conversation to collaborators Dec 14, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
Documentation FrozenDueToAge
Projects
None yet
Milestone
Go1.10
Development

No branches or pull requests
4 participants
@rsc @zwass @ianlancetaylor @gopherbot