Skip to content

cmd/test2json: test output without trailing newline missing final status #57172

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.

Sign up for GitHub

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
Closed
nprintz opened this issue Dec 8, 2022 · 4 comments
Closed

cmd/test2json: test output without trailing newline missing final status #57172

nprintz opened this issue Dec 8, 2022 · 4 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Go1.20

Comments

@nprintz
Copy link

nprintz commented Dec 8, 2022 •
edited
Loading

What version of Go are you using (go version)?

$ go version
go version go1.19.4 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/printz/Library/Caches/go-build"
GOENV="/Users/printz/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/printz/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/printz/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.19.4"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/printz/gh/go/go-test2json-print/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/_p/zjp8mdn93w36g0557gkn5yzm0000gn/T/go-build1303792556=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

When making use of test2json or go test -json, and during the course of a test something is printed to stdout (like with fmt.Print) without a trailing \n, then the test status is not reported in the json event stream.

I believe this behavior stems from here where we do exact byte matching at the start of the each line being handled in test2json (matching itself is a little lower in handleInputLine: https://github.com/golang/go/blob/master/src/cmd/internal/test2json/test2json.go#L170-L175

Repro:

  • clone https://github.com/nprintz/go-test2json-print
    • This repo is simply just two tests, TestPrint that uses fmt.Print with no trailing newline and another (TestPrintln) that uses fmt.Println to expose the difference in behavior with test2json
  • go test . passes fine
  • go test . -json still exits with a 0 status, but the PASS Action of the TestPrint test is not emitted.

What did you expect to see?

I expect to see an additional line noting that the test action was pass for the TestPrint test:

{"Time":"2022-12-08T10:06:13.32384-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Elapsed":0}

I would expect that to show up on line 4 down below, before the run event for the next test.

What did you see instead?

Note that TestPrintln (the second test run) has a line for the event with Action: pass, but the first test, TestPrint does not (even though it passed, as seen in the last Action: output event for that test on Line 3)

$ go test . -json
{"Time":"2022-12-08T10:06:13.323114-06:00","Action":"run","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint"}
{"Time":"2022-12-08T10:06:13.32369-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Output":"=== RUN   TestPrint\n"}
{"Time":"2022-12-08T10:06:13.323779-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Output":"no trailing newline--- PASS: TestPrint (0.00s)\n"}
{"Time":"2022-12-08T10:06:13.323792-06:00","Action":"run","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln"}
{"Time":"2022-12-08T10:06:13.323796-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"=== RUN   TestPrintln\n"}
{"Time":"2022-12-08T10:06:13.3238-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"has a trailing newline\n"}
{"Time":"2022-12-08T10:06:13.323834-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"--- PASS: TestPrintln (0.00s)\n"}
{"Time":"2022-12-08T10:06:13.32384-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Elapsed":0}
{"Time":"2022-12-08T10:06:13.323907-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Output":"PASS\n"}
{"Time":"2022-12-08T10:06:13.324801-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Output":"ok  \tgithub.com/nprintz/go-test2json-print\t0.112s\n"}
{"Time":"2022-12-08T10:06:13.35205-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Elapsed":0.14}
@nprintz
Copy link
Author

nprintz commented Dec 8, 2022

I think this is a question for the community on how we want to handle this case. Some options I see are:

  1. Relax the matching in handleInputLine to look for a suffix of the --- STATUS TestName (#.##s) indicator, rather than exact match at the start of the line.
  2. Continue to use exact matching, but report that the status of the test could not be inferred in some way. This isn't ideal to me, as the test had an underlying result status, it was just lost in translation.
  3. In the test binary, we could always enforce a leading newline before emitting the --- STATUS TestName line, so that exact matching in test2json would continue work with no changes.
  4. Move the responsibility of emitting JSON format away from test2json and into the testing binary itself, so that the reporting is done where the exact status is already known, and we omit this and future bugs that occur when handing off between the two.

@nprintz nprintz changed the title go/test2json: go/test2json: printing without a newline during a test causes test status to be omitted Dec 8, 2022
@seankhliao seankhliao changed the title go/test2json: printing without a newline during a test causes test status to be omitted cmd/test2json: test output without trailing newline missing final status Dec 8, 2022
@seankhliao
Copy link
Member

previously #38063

@seankhliao seankhliao added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Dec 8, 2022
@seankhliao seankhliao added this to the Unplanned milestone Dec 8, 2022
@bcmills
Copy link
Contributor

bcmills commented Dec 12, 2022

@nprintz, does this still reproduce with go1.20rc1? CL 443596 addressed many test2json parsing issues.

@bcmills bcmills added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Dec 12, 2022
@bcmills bcmills modified the milestones: Unplanned, Backlog Dec 12, 2022
@nprintz
Copy link
Author

nprintz commented Dec 13, 2022

@bcmills yeah, it works now:

% go test . -json
{"Time":"2022-12-13T11:14:49.680913-06:00","Action":"start","Package":"github.com/nprintz/go-test2json-print"}
{"Time":"2022-12-13T11:14:49.681265-06:00","Action":"run","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint"}
{"Time":"2022-12-13T11:14:49.681292-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Output":"=== RUN   TestPrint\n"}
{"Time":"2022-12-13T11:14:49.681303-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Output":"no trailing newline"}
{"Time":"2022-12-13T11:14:49.681373-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Output":"--- PASS: TestPrint (0.00s)\n"}
{"Time":"2022-12-13T11:14:49.681386-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrint","Elapsed":0}
{"Time":"2022-12-13T11:14:49.68143-06:00","Action":"run","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln"}
{"Time":"2022-12-13T11:14:49.681437-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"=== RUN   TestPrintln\n"}
{"Time":"2022-12-13T11:14:49.681445-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"has a trailing newline\n"}
{"Time":"2022-12-13T11:14:49.681455-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Output":"--- PASS: TestPrintln (0.00s)\n"}
{"Time":"2022-12-13T11:14:49.681463-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Test":"TestPrintln","Elapsed":0}
{"Time":"2022-12-13T11:14:49.681469-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Output":"PASS\n"}
{"Time":"2022-12-13T11:14:49.681476-06:00","Action":"output","Package":"github.com/nprintz/go-test2json-print","Output":"ok  \tgithub.com/nprintz/go-test2json-print\t(cached)\n"}
{"Time":"2022-12-13T11:14:49.681521-06:00","Action":"pass","Package":"github.com/nprintz/go-test2json-print","Elapsed":0.001}

and I can see the use of -test.v=test2json is needed under the hood to make use of the new marker output.

@nprintz nprintz closed this as completed Dec 13, 2022
@bcmills bcmills modified the milestones: Backlog, Go1.20 Dec 13, 2022
@bcmills bcmills removed the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Dec 13, 2022
@golang golang locked and limited conversation to collaborators Dec 13, 2023
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.
Projects
None yet
Milestone
Go1.20
Development

No branches or pull requests
4 participants
@bcmills @nprintz @gopherbot @seankhliao