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

testing: nested t.Fatalf hides errors #22882

Closed
scubed2 opened this issue Nov 26, 2017 · 7 comments
Closed

testing: nested t.Fatalf hides errors #22882

scubed2 opened this issue Nov 26, 2017 · 7 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@scubed2
Copy link

scubed2 commented Nov 26, 2017

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

go version
go version go1.8 linux/amd64

Does this issue reproduce with the latest release?

(Untested)

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

go env
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/scubed/go"
GORACE=""
GOROOT="/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go"
GOTOOLDIR="/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build180482905=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

I'm not sure how to put a test in the playground.
If someone could point out how to do that, I will.

nested.go
-------------
package nested
-------------
nested_test.go
-------------
package nested

import (
"testing"
)

func TestNested(t *testing.T) {
outer := t
t.Run("sub", func(t *testing.T) {
outer.Fatalf("Nope")
})
}
-------------
Note that renaming t to outer is just for emphasis.

What did you expect to see?

While it's not immediately obvious to me what should happen in this case, it should at least:

  1. Print out the string passed to Fatalf (in this case, "Nope")
  2. If this is invalid, say that it is calling Fatalf from the wrong scope, so people know what the actual problem is.

This came up when debugging a test that was using gomock incorrectly. I ended up spending time tracking down this instead of fixing the test.

What did you see instead?

It gives a not very helpful stacktrace.

go test nested_test.go
panic: test executed panic(nil) or runtime.Goexit

goroutine 6 [running]:
testing.tRunner.func1(0xc420076750)
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/testing/testing.go:622 +0x29d
runtime.Goexit()
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/runtime/panic.go:366 +0x153
testing.(*common).FailNow(0xc4200765b0)
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/testing/testing.go:486 +0x39
testing.(*common).Fatalf(0xc4200765b0, 0x5393ee, 0x4, 0x0, 0x0, 0x0)
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/testing/testing.go:530 +0x83
command-line-arguments.TestNested.func1(0xc420076750)
/dev/shm/a/nested_test.go:10 +0x5c
testing.tRunner(0xc420076750, 0xc42000eea0)
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/testing/testing.go:657 +0x96
created by testing.(*T).Run
/nix/store/5428ij3ln77vam6cacnljc1f75f214fs-go-1.8/share/go/src/testing/testing.go:697 +0x2ca
FAIL command-line-arguments 0.004s

@ianlancetaylor ianlancetaylor changed the title Nested t.Fatalf hides errors testing: nested t.Fatalf hides errors Nov 26, 2017
@ianlancetaylor ianlancetaylor added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Nov 26, 2017
@ianlancetaylor ianlancetaylor added this to the Go1.11 milestone Nov 26, 2017
@agnivade
Copy link
Contributor

agnivade commented Nov 28, 2017

Tested on 1.9 and master. Fails on both.

Simplified the code to use different variables. It's much more clear here -

package nested

import (
	"testing"
)

func TestNested(tt *testing.T) {
        // tt.Fatalf("Nope") // This works as expected
	tt.Run("sub", func(t *testing.T) {
		tt.Fatalf("Nope")
	})
}

Just save this to a file and run go test. It gives a panic.

@creichlin
Copy link

This behavior is triggered because t.Run creates a new goroutine and t.Fatalf calls t.FailNow from that new goroutine which will try to exit the current test by exiting the current goroutine. This is documented in the Run and FailNow method. It should be possible to fix because Run is blocking and while it's blocked a proper error message could be printed before panicking.
I'm not sure though if such a thing is worth fixing, i would say it's rather unlikely to happen and at least it panics so you see that there is something wrong. The added complexity might out-weight the benefit.

@namusyaka
Copy link
Member

Actually, I think this is a corner case, but the current behavior is not intuitive.

For example, I guess we can fix the issue with such a change.

diff --git src/testing/testing.go src/testing/testing.go
index f56dbf8f6d..6bd03b703b 100644
--- src/testing/testing.go
+++ src/testing/testing.go
@@ -733,7 +733,7 @@ func tRunner(t *T, fn func(t *T)) {
                t.duration += time.Since(t.start)
                // If the test panicked, print any test output before dying.
                err := recover()
-               if !t.finished && err == nil {
+               if (t.parent != nil && !t.parent.finished) && !t.finished && err == nil {
                        err = fmt.Errorf("test executed panic(nil) or runtime.Goexit")
                }
                if err != nil {

and then, got:

=== RUN   TestNested
=== RUN   TestNested/sub
--- FAIL: TestNested (0.00s)
	main_test.go:10: Nope
    --- PASS: TestNested/sub (0.00s)
FAIL

What do you think? I can send a CL if you hope.

@gopherbot
Copy link

Change https://golang.org/cl/87835 mentions this issue: testing: don't overwrite error unless parent of subtest is finished

@namusyaka
Copy link
Member

namusyaka commented Jan 16, 2018

I've rethink this issue, and then I strongly thought that this problem should be fixed. Anyway, I will send the CL to do this discussion productively, then I decided to wait for go-1.11 development cycle.
Thanks.

@gopherbot
Copy link

Change https://golang.org/cl/97635 mentions this issue: testing: gracefully handle subtest failing parent’s T

@mpvl
Copy link
Contributor

mpvl commented Feb 28, 2018

@namusyaka I agree that the current behavior is undesirable. Thanks for the CL. It comes close to a fix, but has some remaining issues. I've created another CL which I believe comes to a good compromise. It treats calling FailNow on a parent as an error, but will still handle it gracefully without panicking.

If we decide in the future that this is not an error, we need to handle the case of parallel subtests calling FailNow on a parent concurrently. This will be very tricky to get right.

@golang golang locked and limited conversation to collaborators Mar 1, 2019
@golang golang unlocked this conversation Jun 27, 2023
@golang golang locked as resolved and limited conversation to collaborators Jun 27, 2023
@golang golang unlocked this conversation Jun 27, 2023
@golang golang locked as resolved and limited conversation to collaborators Jun 27, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

7 participants