From 23e68d7651a0017a6fc8223a964ec3d6db53d4bb Mon Sep 17 00:00:00 2001 From: Russ Cox Date: Thu, 14 Dec 2017 14:53:40 -0500 Subject: [PATCH] cmd/go: fix caching of test -json outputs go test -json was inadvertently disabling caching. Fix that. Fixes #22984. Change-Id: Ic933a8c8ac00ce8253e934766954b1ccc6ac0cec Reviewed-on: https://go-review.googlesource.com/84075 Run-TryBot: Russ Cox Reviewed-by: Ian Lance Taylor --- src/cmd/go/go_test.go | 3 + src/cmd/go/internal/test/test.go | 115 ++++++++++++++++----------- src/cmd/go/internal/test/testflag.go | 2 +- 3 files changed, 73 insertions(+), 47 deletions(-) diff --git a/src/cmd/go/go_test.go b/src/cmd/go/go_test.go index 8cf9cfbb10..1e9552eff4 100644 --- a/src/cmd/go/go_test.go +++ b/src/cmd/go/go_test.go @@ -5423,6 +5423,9 @@ func TestGoTestJSON(t *testing.T) { tg.grepStdout(`"Action":"output","Package":"skipper","Test":"Test","Output":"--- SKIP:`, "did not see SKIP output") tg.grepStdout(`"Action":"skip","Package":"skipper","Test":"Test"`, "did not see skip result for Test") + tg.run("test", "-json", "-short", "-v", "errors") + tg.grepStdout(`"Action":"output","Package":"errors","Output":".*\(cached\)`, "did not see no cached output") + tg.run("test", "-json", "-bench=NONE", "-short", "-v", "errors") tg.grepStdout(`"Package":"errors"`, "did not see JSON output") tg.grepStdout(`"Action":"run"`, "did not see JSON output") diff --git a/src/cmd/go/internal/test/test.go b/src/cmd/go/internal/test/test.go index 7f8954a7d9..b224d8a46d 100644 --- a/src/cmd/go/internal/test/test.go +++ b/src/cmd/go/internal/test/test.go @@ -1249,6 +1249,52 @@ func (lockedStdout) Write(b []byte) (int, error) { // builderRunTest is the action for running a test binary. func (c *runCache) builderRunTest(b *work.Builder, a *work.Action) error { + if a.Failed { + // We were unable to build the binary. + a.Failed = false + a.TestOutput = new(bytes.Buffer) + fmt.Fprintf(a.TestOutput, "FAIL\t%s [build failed]\n", a.Package.ImportPath) + base.SetExitStatus(1) + return nil + } + + var stdout io.Writer = os.Stdout + if testJSON { + json := test2json.NewConverter(lockedStdout{}, a.Package.ImportPath, test2json.Timestamp) + defer json.Close() + stdout = json + } + + var buf bytes.Buffer + if len(pkgArgs) == 0 || testBench { + // Stream test output (no buffering) when no package has + // been given on the command line (implicit current directory) + // or when benchmarking. + // 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 + } + } + if c.buf == nil { // We did not find a cached result using the link step action ID, // so we ran the link step. Try again now with the link output @@ -1262,19 +1308,14 @@ func (c *runCache) builderRunTest(b *work.Builder, a *work.Action) error { c.tryCacheWithID(b, a, a.Deps[0].BuildContentID()) } if c.buf != nil { + if stdout != &buf { + stdout.Write(c.buf.Bytes()) + c.buf.Reset() + } a.TestOutput = c.buf return nil } - if a.Failed { - // We were unable to build the binary. - a.Failed = false - a.TestOutput = new(bytes.Buffer) - fmt.Fprintf(a.TestOutput, "FAIL\t%s [build failed]\n", a.Package.ImportPath) - base.SetExitStatus(1) - return nil - } - execCmd := work.FindExecCmd() testlogArg := []string{} if !c.disableCache && len(execCmd) == 0 { @@ -1301,42 +1342,8 @@ func (c *runCache) builderRunTest(b *work.Builder, a *work.Action) error { cmd := exec.Command(args[0], args[1:]...) cmd.Dir = a.Package.Dir cmd.Env = base.EnvForDir(cmd.Dir, cfg.OrigEnv) - var buf bytes.Buffer - var stdout io.Writer = os.Stdout - if testJSON { - json := test2json.NewConverter(lockedStdout{}, a.Package.ImportPath, test2json.Timestamp) - defer json.Close() - stdout = json - } - if len(pkgArgs) == 0 || testBench { - // Stream test output (no buffering) when no package has - // been given on the command line (implicit current directory) - // or when benchmarking. - cmd.Stdout = 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. - cmd.Stdout = io.MultiWriter(stdout, &buf) - } else { - cmd.Stdout = &buf - } - } - cmd.Stderr = cmd.Stdout + cmd.Stdout = stdout + cmd.Stderr = stdout // If there are any local SWIG dependencies, we want to load // the shared library from the build directory. @@ -1401,7 +1408,7 @@ func (c *runCache) builderRunTest(b *work.Builder, a *work.Action) error { if err == nil { norun := "" - if !testShowPass { + if !testShowPass && !testJSON { buf.Reset() } if bytes.HasPrefix(out, noTestsToRun[1:]) || bytes.Contains(out, noTestsToRun) { @@ -1436,6 +1443,9 @@ func (c *runCache) tryCacheWithID(b *work.Builder, a *work.Action, id string) bo if len(pkgArgs) == 0 { // Caching does not apply to "go test", // only to "go test foo" (including "go test ."). + if cache.DebugTest { + fmt.Fprintf(os.Stderr, "testcache: caching disabled in local directory mode\n") + } c.disableCache = true return false } @@ -1444,6 +1454,9 @@ func (c *runCache) tryCacheWithID(b *work.Builder, a *work.Action, id string) bo for _, arg := range testArgs { i := strings.Index(arg, "=") if i < 0 || !strings.HasPrefix(arg, "-test.") { + if cache.DebugTest { + fmt.Fprintf(os.Stderr, "testcache: caching disabled for test argument: %s\n", arg) + } c.disableCache = true return false } @@ -1465,12 +1478,18 @@ func (c *runCache) tryCacheWithID(b *work.Builder, a *work.Action, id string) bo default: // nothing else is cacheable + if cache.DebugTest { + fmt.Fprintf(os.Stderr, "testcache: caching disabled for test argument: %s\n", arg) + } c.disableCache = true return false } } if cache.Default() == nil { + if cache.DebugTest { + fmt.Fprintf(os.Stderr, "testcache: GOCACHE=off\n") + } c.disableCache = true return false } @@ -1712,6 +1731,10 @@ func testAndInputKey(testID, testInputsID cache.ActionID) cache.ActionID { } func (c *runCache) saveOutput(a *work.Action) { + if c.id1 == (cache.ActionID{}) && c.id2 == (cache.ActionID{}) { + return + } + // See comment about two-level lookup in tryCacheWithID above. testlog, err := ioutil.ReadFile(a.Objdir + "testlog.txt") if err != nil || !bytes.HasPrefix(testlog, testlogMagic) || testlog[len(testlog)-1] != '\n' { diff --git a/src/cmd/go/internal/test/testflag.go b/src/cmd/go/internal/test/testflag.go index 8a908f7e21..8a686b7125 100644 --- a/src/cmd/go/internal/test/testflag.go +++ b/src/cmd/go/internal/test/testflag.go @@ -137,7 +137,7 @@ func testFlags(args []string) (packageNames, passToTest []string) { case "c", "i", "v", "cover", "json": cmdflag.SetBool(cmd, f.BoolVar, value) if f.Name == "json" && testJSON { - passToTest = append(passToTest, "-test.v") + passToTest = append(passToTest, "-test.v=true") } case "o": testO = value