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

runtime: test output is very noisy #38594

Closed
bcmills opened this issue Apr 22, 2020 · 3 comments
Closed

runtime: test output is very noisy #38594

bcmills opened this issue Apr 22, 2020 · 3 comments

Comments

@bcmills
Copy link
Member

@bcmills bcmills commented Apr 22, 2020

At some point recently (within the 1.15 cycle), the runtime test failures have started to include a lot of mysterious recurseFn, methodN and did recover noise that isn't clearly associated with any test function.

Either the purpose of this output should be made clearer, or the output should be suppressed or clearly associated with a specific test.

Tentatively marking as release-blocker for 1.15, because if the runtime test fails on a user's machine I think this noise will make it very difficult for them to figure out what is wrong.

CC @aclements @randall77 @danscales

@bcmills
Copy link
Member Author

@bcmills bcmills commented Apr 22, 2020

An example (https://build.golang.org/log/dd547a9133c41d38ea6c4c0e5a7c5d8541c7b7b2):

--- FAIL: TestSegv (0.00s)
    --- FAIL: TestSegv/Segv (0.01s)
        crash_cgo_test.go:569: 
        crash_cgo_test.go:571: expected crash from signal
    --- FAIL: TestSegv/SegvInCgo (0.01s)
        crash_cgo_test.go:569: 
        crash_cgo_test.go:571: expected crash from signal
recurseFn 0 4294967295
recurseFn 1 4294967295
recurseFn 2 4294967295
recurseFn 3 4294967295
recurseFn 4 4294967295
recurseFn 5 4294967295
recurseFn 6 4294967295
recurseFn 7 4294967295
recurseFn 8 4294967295
recurseFn 0 4294967295
recurseFn 1 4294967295
recurseFn 2 4294967295
recurseFn 3 4294967295
recurseFn 4 4294967295
recurseFn 5 4294967295
recurseFn 6 4294967295
recurseFn 7 4294967295
recurseFn 8 4294967295
recurseFn 0 4294967295
recurseFn 1 4294967295
recurseFn 2 4294967295
recurseFn 3 4294967295
recurseFn 4 4294967295
recurseFn 5 4294967295
recurseFn 6 4294967295
recurseFn 7 4294967295
recurseFn 8 4294967295
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
did recover
debug &{} 1 2 3 4 5 6 7 8
method1
finished recursion 0
method1
method2
method1
FAIL
FAIL	runtime	41.529s

I can't tell from that output what, if anything, all of those lines have to do with the failing TestSegv function, and if I were running that test in a terminal the actual failure message would be pushed well offscreen by all of the noise that follows it.

@danscales danscales self-assigned this Apr 22, 2020
@danscales
Copy link

@danscales danscales commented Apr 22, 2020

That's in one of my tests, I clean that up. Thanks for pointing that out.

@gopherbot
Copy link

@gopherbot gopherbot commented Apr 22, 2020

Change https://golang.org/cl/229538 mentions this issue: runtime: fix TestDeferWithRepeatedRepanics and TestIssue37688 to be less chatty

@gopherbot gopherbot closed this in 939379f Apr 23, 2020
xujianhai666 added a commit to xujianhai666/go-1 that referenced this issue May 21, 2020
…ess chatty

Converted some Println() statements (used to make sure that certain variables were
kept alive and not optimized out) to assignments into global variables, so the
tests don't produce extraneous output when there is a failure.

Fixes golang#38594

Change-Id: I7eb41bb02b2b1e78afd7849676b5c85bc11c759c
Reviewed-on: https://go-review.googlesource.com/c/go/+/229538
Run-TryBot: Dan Scales <danscales@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
3 participants
You can’t perform that action at this time.