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

cmd/go: go test -v -run TestFoo ./... does not stream test output when multiple packages present but test regex only matches tests from a single package #49195

Closed
MadLittleMods opened this issue Oct 27, 2021 · 4 comments
Labels
FrozenDueToAge GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Unfortunate

Comments

@MadLittleMods
Copy link

MadLittleMods commented Oct 27, 2021

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

$ go version
go version go1.16.6 darwin/amd64

Does this issue reproduce with the latest release?

Untested but the relevant code still looks the same

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/eric/Library/Caches/go-build"
GOENV="/Users/eric/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/eric/.gvm/pkgsets/go1.16.6/global/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/eric/.gvm/pkgsets/go1.16.6/global"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/Users/eric/.gvm/gos/go1.16.6"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/Users/eric/.gvm/gos/go1.16.6/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.16.6"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/eric/Documents/github/go/src/go.mod"
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/5r/34hr5d_x7995nj8wk77dj_n40000gn/T/go-build3417095465=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

Run go test -v -run TestFoo ./... in a Go module that has multiple packages present. Where TestFoo only matches tests in a single package.

What did you expect to see?

I expected to see the logs streamed as the tests run.

I especially expected this to work since all of the tests matching the regex( -run TestFoo) are from a single package which is already supported to stream and only stopped working once an unrelated package was added to the tests directory.

What did you see instead?

All test output is buffered and only printed when the tests completely finish.

Potential solutions

This is highly related to #46959 and #27826 but I didn't want to muddy up those issues aiming to solve a slightly different use case even though a solution there would probably also solve my use case.

Do any of these seem viable for a PR/CL?

  1. Stream logs from all packages (magic)
  2. Always stream the first package and printed rest of the buffered output afterwards
    • This seems like an interesting compromise! But adds a bit more magic to the stream vs buffered behavior.
  3. Since streaming is already supported when a single package is present, detect when -run only matches tests from a single package and stream.
  4. Add new command-line option to override the buffer/stream behavior

Relevant Go source code

Here is the code on how Go decides to stream or buffer the output from the test binaries of multiple packages:

var buf bytes.Buffer
if len(pkgArgs) == 0 || testBench != "" || testFuzz != "" {
// Stream test output (no buffering) when no package has
// been given on the command line (implicit current directory)
// or when benchmarking or fuzzing.
// No change to stdout.
} else {
// If we're only running a single package under test or if parallelism is
// set to 1, and if we're displaying all output (testShowPass), we can
// hurry the output along, echoing it as soon as it comes in.
// We still have to copy to &buf for caching the result. This special
// case was introduced in Go 1.5 and is intentionally undocumented:
// the exact details of output buffering are up to the go command and
// subject to change. It would be nice to remove this special case
// entirely, but it is surely very helpful to see progress being made
// when tests are run on slow single-CPU ARM systems.
//
// If we're showing JSON output, then display output as soon as
// possible even when multiple tests are being run: the JSON output
// events are attributed to specific package tests, so interlacing them
// is OK.
if testShowPass() && (len(pkgs) == 1 || cfg.BuildP == 1) || testJSON {
// Write both to stdout and buf, for possible saving
// to cache, and for looking for the "no tests to run" message.
stdout = io.MultiWriter(stdout, &buf)
} else {
stdout = &buf
}
}

Here is where it loops over the packages and runs a test binary for each (a test binary is run/created for each package found/specified),

// Prepare build + run + print actions for all packages being tested.
for _, p := range pkgs {
// sync/atomic import is inserted by the cover tool. See #18486
if testCover && testCoverMode == "atomic" {
ensureImport(p, "sync/atomic")
}
buildTest, runTest, printTest, err := builderTest(&b, ctx, pkgOpts, p)

Checking the -v verbose flag and creating a chattyPrinter,

go/src/testing/testing.go

Lines 1804 to 1806 in c0ac39c

if Verbose() {
t.chatty = newChattyPrinter(t.w)
}


Tracking this internally at matrix-org/complement#215

Keywords: print, stream, log

@MadLittleMods MadLittleMods changed the title cmd/go: go test -v -run TestFoo ./... does not stream test output when multiple packages present cmd/go: go test -v -run TestFoo ./... does not stream test output when multiple packages present when test regex only matches tests from a single package Oct 27, 2021
@MadLittleMods MadLittleMods changed the title cmd/go: go test -v -run TestFoo ./... does not stream test output when multiple packages present when test regex only matches tests from a single package cmd/go: go test -v -run TestFoo ./... does not stream test output when multiple packages present but test regex only matches tests from a single package Oct 27, 2021
@seankhliao seankhliao added GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 28, 2021
@seankhliao
Copy link
Member

cc @bcmills @matloob

@bcmills
Copy link
Member

bcmills commented Oct 28, 2021

I agree that it's a bit annoying to have to specify the package you want to test explicitly, but it seems rare enough to know that the test case isn't duplicated across any other packages that I don't think this is worth the complexity to fix.

@bcmills
Copy link
Member

bcmills commented Oct 29, 2021

Closing as not viable to fix. (Specifically, the streaming vs. non-streaming behavior would be too difficult for users to predict — in this case, the extra work of naming a specific package provides an extra invariant that the package matching the test pattern is necessarily unique.)

@bcmills bcmills closed this as completed Oct 29, 2021
@MadLittleMods
Copy link
Author

MadLittleMods commented Oct 29, 2021

Thanks for the thoughts @bcmills 🙂 - This issue is spawning from wishing streaming would work out of the box somehow and for others not have to understand the nuance. Was also hoping for some possible better ideas 😁

the extra work of naming a specific package provides an extra invariant that the package matching the test pattern necessarily unique.

Interesting note here 👍

the streaming vs. non-streaming behavior would be too difficult for users to predict

A "new command-line option to override the buffer/stream behavior" seems like the easiest to predict. But I understand that this isn't necessarily that different from specifying a package (both end-up require changing your command to get streaming). Although specifying a package is very indirect to understand.


As a note, the current behavior is hard to understand and I had to do some Googling why it wasn't streaming anymore. First stumbled on https://dave.cheney.net/2020/03/10/go-test-v-streaming-output from Googling go testing change output and saw I was already using -v and then had to Google "go test -v" no longer streaming output to find #46959 and noticed that someone did recently add a new package to the tests directory to cause the problem. Looking forward to the doc updates that might come out of that.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge GoCommand cmd/go NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Unfortunate
Projects
None yet
Development

No branches or pull requests

4 participants