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

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
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Go1.15

Comments

@bcmills
Copy link
Contributor

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 bcmills added Testing An issue that has been verified to require only test changes, not just a test failure. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker labels Apr 22, 2020
@bcmills bcmills added this to the Go1.15 milestone Apr 22, 2020
@bcmills
Copy link
Contributor Author

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
Contributor

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

@gopherbot
Copy link

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

xujianhai666 pushed a commit to xujianhai666/go-1 that referenced this issue May 21, 2020
@danscales @xujianhai666
runtime: fix TestDeferWithRepeatedRepanics and TestIssue37688 to be l…
a2e3215 
…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>
@golang golang locked and limited conversation to collaborators Apr 23, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Milestone
Go1.15
Development

No branches or pull requests
3 participants
@danscales @bcmills @gopherbot