testing: output hard to read when a test case is stalling

[rakyll]

When the package contains a stalling case, the verbose is hard to read to figure out what has run and not finished finished yet. I often have to pipe the output to another program to match RUNs and PASSes (or FAILs) to filter what has not finished.

We might just consider printing the currently running test cases upon SIGINT.

go test -v
=== RUN   TestTrace
=== RUN   TestTraceWithWait
--- PASS: TestTraceWithWait (0.01s)
=== RUN   TestTraceFromHeader
=== RUN   TestTraceFromHeaderWithWait
--- PASS: TestTraceFromHeaderWithWait (2.00s)
=== RUN   TestNewSpan
--- PASS: TestNewSpan (0.01s)
=== RUN   TestNoTrace
--- PASS: TestNoTrace (0.04s)
=== RUN   TestNoTraceWithWait
--- PASS: TestNoTraceWithWait (0.14s)
=== RUN   TestNoTraceFromHeader
--- PASS: TestNoTraceFromHeader (0.04s)
=== RUN   TestNoTraceFromHeaderWithWait
--- PASS: TestNoTraceFromHeaderWithWait (0.04s)
=== RUN   TestSample
--- PASS: TestSample (0.00s)
=== RUN   TestSampling
=== RUN   TestBundling
=== RUN   TestWeights
--- PASS: TestWeights (0.02s)
=== RUN   TestPropagation
--- PASS: TestPropagation (0.00s)
=== RUN   TestNoTraceIncoming
--- PASS: TestNoTraceIncoming (0.00s)
--- PASS: TestSampling (1.98s)
--- PASS: TestTrace (2.00s)
--- PASS: TestTraceFromHeader (2.00s)
^Csignal: interrupt
FAIL	cloud.google.com/go/trace	189.182s

[klingtnet]

I would like to have a command line flag like go test -only-failed which omits passed tests in the output.
This would make it very easy to spot failed test runs even for very large test suites and without the need of changing the output format.
This is already go tests default behavior.

[bradfitz]

@klingtnet, we don't need a new flag because that is already the default behavior.

[klingtnet]

@bradfitz Sorry, I misunderstood the initial question which was about stalling not failing tests.
Anyways, I always run go test -v so I didn't knew that showing only failed tests is the default behavior which is luckily exactly what I want. Thanks for pointing this out.

[meirf]

Some notes:

• To be more specific on the use of the word "stalling": currently in practice this only applies to test cases running in Parallel. Parallel test cases aren't necessarily slow, but rather their executions are delayed ("stalled") such that all Parallel tests run in parallel. So even though the output shows "RUN" next to their test name, their executions and therefore terminations ("PASS", "FAIL") might happen after the next test's RUN, which makes the output hard to read. But even though in practice this illegibility might only occur for Parallel tests, in theory and for the implementation of the code change, the fact that this is only for Parallel tests should be ignored. To safeguard against changes to the Parallel implementation, we should just follow rakyll's advice to print any currently running tests on SIGINT.
• b.Do(root) is where the test action tree is run. While this is running, need to make sure SIGINTs can be (1) captured and (2) acted on.
• cmd.Start() is the start of each specific test. When this command is started a test should be considered in progress. Either when this command completes naturally or is stopped/killed externally, can consider it no longer running.

(I'd like to work on this - I realize we're in a freeze and that the code might not qualify for review since it's tooling-related and not an actual test.)

[gopherbot]

CL https://golang.org/cl/44352 mentions this issue.

[gopherbot]

CL https://golang.org/cl/48370 mentions this issue.

[ianlancetaylor]

I rolled back the first fix for this issue. It changed the behavior of SIGINT, which affects tests that use SIGINT. I think that a patch along those lines can only be used if there is a way to check whether the code under test is using SIGINT, but the os/signal package does not currently provide any API for that.