gotestsum icon indicating copy to clipboard operation
gotestsum copied to clipboard

parse outputs for garbled passes to avoid spurious failures

Open MisterSquishy opened this issue 3 years ago • 3 comments

Implements this suggestion -- updates the execution to search output events for the PASS output string. It will then count those as pass events (if no true pass event is encountered). As per https://github.com/golang/go/issues/26325, test2json occasionally has issues with interleaving stdout logs and test result logs, leading to output lines like

"Output":"[example.go--- PASS: TestExample (0.08s)\n"

The extra text in the output breaks test2json's ability to detect that this is in fact a pass, and as a result we get neither a pass nor fail event in the output json. With this change, we will still be able to count this as a pass.

MisterSquishy avatar Jun 01 '22 19:06 MisterSquishy

Thank you for the PR, and for your interest in fixing this problem!

I'm hoping this problem is fixed in the stdlib at some point. I think the solution proposed in https://github.com/golang/go/issues/26325#issuecomment-880034679 would work quite well, and would be much easier to implement in test2json. That way the last "end event" will fix any problems with duplicate events.

It's possible that we can work around the problem in gotestsum, although I hope we can do so without a regex. We should be able to use similar logic to what test2json uses without the requirement of a newline. I'd have to look again, but I think it probably looks for the literal string --- PASS: Test, using something like strings.IndexOf, or strings.Cut.

Do you have examples of when you run into this problem? Is it developers forgetting to add a \n to log messages, or does something else cause the problem?

dnephin avatar Jun 13 '22 01:06 dnephin

One way to work around problems like this is to add something like this to any test setup functions:

t.Cleanup(func() {
    t.Log("\n")
})

As long as that is the last cleanup function to run, it should guarantee at least one trailing newline.

dnephin avatar Jun 15 '22 20:06 dnephin

Do you have examples of when you run into this problem? Is it developers forgetting to add a \n to log messages, or does something else cause the problem?

I'm specifically encountering it in tests that have asynchronous processes logging shutdown messages at the same time that the test results are being logged. I've been looking for library-level fixes as opposed to test-level fixes, as the codebase has tens of thousands of tests.

I can take a stab at tackling https://github.com/golang/go/issues/26325#issuecomment-880034679 in test2json instead!

MisterSquishy avatar Jun 16 '22 20:06 MisterSquishy

It sounds like https://go-review.googlesource.com/c/go/+/443596 has probably fixed the issue, and that fix should be in the next go release (go1.20).

Thank you for your work to get this issue fixed! I'm going to close this PR since we have a fix coming in the next Go release.

dnephin avatar Nov 26 '22 21:11 dnephin