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: using "go tool test2json dlv test-binary" marks the last test as failed on Mac OS #34286

Closed
nd opened this issue Sep 13, 2019 · 9 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@nd
Copy link
Contributor

nd commented Sep 13, 2019

This is continuation of #23033 which is still actual in go1.13.

To reproduce the issue create <GOPATH>/src/debugTest/foo_test.go:

package foo

import "testing"

func Test1(t *testing.T) {
}

compile it:

go test -c -o testBinary -gcflags "all=-N -l" debugTest

run:

go tool test2json dlv --listen=:2345 --headless exec testBinary -- -test.v

and connect debugger from another console: dlv connect :2345.

In the Delve console type continue and once the testBinary terminates, exit the delve client via the exit command.

Test2json produces output:

{"Action":"run","Test":"Test1"}
{"Action":"output","Test":"Test1","Output":"=== RUN   Test1\r\n"}
{"Action":"output","Test":"Test1","Output":"--- PASS: Test1 (0.00s)\r\n"}
{"Action":"output","Test":"Test1","Output":"PASS\r\n"}
{"Action":"fail","Test":"Test1"}

This happens because on Mac OS Delve runs programs via debugserver and debugserver uses \r\n line-endings. For most of test output it is not a problem because test2json check prefixes and is not affected by line-ending differences. But for final PASS or FAIL the exact Equal check is used and it fails due to added \r.

This behavior was accidentally fixed in d47526e, but judging by comments in #31969 the fix will be reverted later.

I understand that this is not a bug in test2json. Test2json assumes the output is produced by the test framework and the test framework always uses \n. It is possible to wrap Delve and replace PASS\r\n in its output to PASS\n, but every test2json client will have to do that. Maybe it is possible to support this case in test2json itself?

In #23033 there was a question: why one would want to debug a test and also see the its final status. The most relevant use-case I can think of is a modification of a program state during debug session. Let's say I have a complex algorithm test for which started to fail. During a debug session I've found a potential problem. I cannot easily change the sources and rerun a test because the fix is complicated, but I can change the program state at runtime. I want to verify that changing some value in a program produces a desirable effect and test starts to pass. At the moment it is not possible as the test status is always "fail".

@ianlancetaylor ianlancetaylor changed the title Test2json marks the last test as failed on Mac OS testing: using "go tool test2json dlv test-binary" marks the last test as failed on Mac OS Sep 13, 2019
@ianlancetaylor
Copy link
Contributor

Why do you run

go tool test2json dlv --listen=:2345 --headless exec testBinary -- -test.v

instead of

dlv --listen=:2345 --headless exec testBinary -- -test.v

? How does running under go tool test2json make it easier to debug the program?

@ianlancetaylor
Copy link
Contributor

Why does delve output \r\n rather than \n when its standard output is not a terminal? Where is that coming from?

@nd
Copy link
Contributor Author

nd commented Sep 13, 2019

Test2json is used to simplify test output parsing, json is easier to parse than the raw output produced by test executable. Test2json output is consumed by an editor and is shown in a dedicated UI where each test has an icon according to its status. It is easier to grasp tests status from such a view than from reading output of all tests. Test2json doesn't change the debugging experience per se, but it is useful to be able both debug a test and see its outcome once debug session is over.

If I understand correctly Delve redirects debugserver output to its stdout without changing anything. @aarzilli could you please confirm?

@aarzilli
Copy link
Contributor

This thing with tests getting \r\n on macOS came out before and I couldn't figure out where it happens. The way it works is that delve runs the test executable under debugserver and then debugserver sends us the output in a stop packet (it's the 'O' kind). It already contains the \r there so either debugserver is adding it (werid) or possibly the tty layer in the kernel (weirder).

@toothrot toothrot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 16, 2019
@toothrot toothrot added this to the Unplanned milestone Sep 16, 2019
@asilverman
Copy link

asilverman commented Dec 20, 2019

@rsc Why not simply add :
|| bytes.Equal(line, []byte("PASS\r\n"))
to line 158 and 161 and be done with it ?

func (c *converter) handleInputLine(line []byte) {
// Final PASS or FAIL.
if bytes.Equal(line, bigPass) || bytes.Equal(line, bigFail) {
c.flushReport(0)
c.output.write(line)
if bytes.Equal(line, bigPass) {
c.result = "pass"
} else {
c.result = "fail"
}
return
}

@peterhuson
Copy link

bump
This breaks GoLand test parsing: https://youtrack.jetbrains.com/issue/GO-6493

@nd
Copy link
Contributor Author

nd commented Jul 17, 2020

It looks like debugserver creates a new pseudo terminal for the inferior and by default terminal has the ONLCR flag set which maps NL to CR-NL.

@gopherbot
Copy link

Change https://go.dev/cl/428715 mentions this issue: test2json: tolerate \r\n as a newline separator in test output

@gopherbot
Copy link

Change https://go.dev/cl/443596 mentions this issue: testing: fix many test2json inaccuracies

romaindoumenc pushed a commit to TroutSoftware/go that referenced this issue Nov 3, 2022
Test2json is parsing the output stream from the test, which includes
package testing's own framing lines intermingled with other output,
in particular any output printed via fmt.Printf, println, and so on.
We have had recurring problems with unexpected partial output lines
causing a framing line to be missed.

A recent talk at GopherCon gave an example of an integration test
involving Docker that happened to print \r-terminated lines instead
of \n-terminated lines in some configurations, which in turn broke
test2json badly. (https://www.gophercon.com/agenda/session/944259)

There are also a variety of open reported issues with similar problems,
which this CL also addresses. The general approach is to add a new
testing flag -test.v=json that means to print additional output to help
test2json. And then test2json takes advantage of that output.

Among the fixes:

 - Identify testing framing more reliably, using ^V
   (golang#23036, golang#26325, golang#43683, GopherCon talk)
 - Test that output with \r\n endings is handled correctly
   (golang#43683, golang#34286)
 - Use === RUN in fuzz tests (golang#52636, golang#48132)
 - Add === RUN lines to note benchmark starts (golang#27764, golang#49505)
 - Print subtest --- PASS/FAIL lines as they happen (golang#29811)
 - Add === NAME lines to emit more test change events,
   such as when a subtest stops and the parent continues running.
 - Fix event shown in overall test failure (golang#27568)
 - Avoid interleaving of writes to os.Stdout and os.Stderr (golang#33419)

Fixes golang#23036.
Fixes golang#26325.
Fixes golang#27568.
Fixes golang#27764.
Fixes golang#29811.
Fixes golang#33419.
Fixes golang#34286.
Fixes golang#43683.
Fixes golang#49505.
Fixes golang#52636.

Change-Id: Id4207b746a20693f92e52d68c6e4a7f8c41cc7c6
Reviewed-on: https://go-review.googlesource.com/c/go/+/443596
Auto-Submit: Russ Cox <rsc@golang.org>
Run-TryBot: Russ Cox <rsc@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@dmitshur dmitshur added NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 18, 2022
@dmitshur dmitshur modified the milestones: Unplanned, Go1.20 Nov 18, 2022
@golang golang locked and limited conversation to collaborators Nov 18, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
8 participants