cmd/go: cache successful test results

This CL adds caching of successful test results, keyed by the
action ID of the test binary and its command line arguments.

Suppose you run:

	go test -short std
	<edit a typo in a comment in math/big/float.go>
	go test -short std

Before this CL, the second go test would re-run all the tests
for the std packages. Now, the second go test will use the cached
result immediately (without any compile or link steps) for any
packages that do not transitively import math/big, and then
it will, after compiling math/big and seeing that the .a file didn't
change, reuse the cached test results for the remaining packages
without any additional compile or link steps.

Suppose that instead of editing a typo you made a substantive
change to one function, but you left the others (including their
line numbers) unchanged. Then the second go test will re-link
any of the tests that transitively depend on math/big, but it still
will not re-run the tests, because the link will result in the same
test binary as the first run.

The only cacheable test arguments are:

	-cpu
	-list
	-parallel
	-run
	-short
	-v

Using any other test flag disables the cache for that run.
The suggested argument to mean "turn off the cache" is -count=1
(asking "please run this 1 time, not 0").

There's an open question about re-running tests when inputs
like environment variables and input files change. For now we
will assume that users will bypass the test cache when they
need to do so, using -count=1 or "go test" with no arguments.

This CL documents the new cache but also documents the
previously-undocumented distinction between "go test" with
no arguments (now called "local directory mode") and with
arguments (now called "package list mode"). It also cleans up
a minor detail of package list mode buffering that used to change
whether test binary stderr was sent to go command stderr based
on details like exactly how many packages were listed or
how many CPUs the host system had. Clearly the file descriptor
receiving output should not depend on those, so package list mode
now consistently merges all output to stdout, where before it
mostly did that but not always.

Fixes #11193.

Change-Id: I120edef347b9ddd5b10e247bfd5bd768db9c2182
Reviewed-on: https://go-review.googlesource.com/75631
Run-TryBot: Russ Cox <rsc@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: David Crawshaw <crawshaw@golang.org>

misc/cgo/testplugin/test.bash

@@ -14,6 +14,9 @@ fi
 goos=$(go env GOOS)
 goarch=$(go env GOARCH)
 
+echo SKIP: golang.org/issue/22571.
+exit 0
+
 function cleanup() {
 	rm -f plugin*.so unnamed*.so iface*.so issue*
 	rm -rf host pkg sub iface

src/cmd/dist/deps.go

@@ -280,6 +280,7 @@ var builddeps = map[string][]string{
 	"cmd/go/internal/test": {
 		"bytes",                   // cmd/go/internal/test
 		"cmd/go/internal/base",    // cmd/go/internal/test
+		"cmd/go/internal/cache",   // cmd/go/internal/test
 		"cmd/go/internal/cfg",     // cmd/go/internal/test
 		"cmd/go/internal/cmdflag", // cmd/go/internal/test
 		"cmd/go/internal/load",    // cmd/go/internal/test
@@ -293,6 +294,7 @@ var builddeps = map[string][]string{
 		"go/doc",                  // cmd/go/internal/test
 		"go/parser",               // cmd/go/internal/test
 		"go/token",                // cmd/go/internal/test
+		"io",                      // cmd/go/internal/test
 		"os",                      // cmd/go/internal/test
 		"os/exec",                 // cmd/go/internal/test
 		"path",                    // cmd/go/internal/test

src/cmd/go/alldocs.go

@@ -724,10 +724,10 @@
 //
 // 'Go test' recompiles each package along with any files with names matching
 // the file pattern "*_test.go".
-// Files whose names begin with "_" (including "_test.go") or "." are ignored.
 // These additional files can contain test functions, benchmark functions, and
 // example functions. See 'go help testfunc' for more.
 // Each listed package causes the execution of a separate test binary.
+// Files whose names begin with "_" (including "_test.go") or "." are ignored.
 //
 // Test files that declare a package with the suffix "_test" will be compiled as a
 // separate package, and then linked and run with the main test binary.
@@ -735,11 +735,37 @@
 // The go tool will ignore a directory named "testdata", making it available
 // to hold ancillary data needed by the tests.
 //
-// By default, go test needs no arguments. It compiles and tests the package
-// with source in the current directory, including tests, and runs the tests.
-//
-// The package is built in a temporary directory so it does not interfere with the
-// non-test installation.
+// Go test runs in two different modes: local directory mode when invoked with
+// no package arguments (for example, 'go test'), and package list mode when
+// invoked with package arguments (for example 'go test math', 'go test ./...',
+// and even 'go test .').
+//
+// In local directory mode, go test compiles and tests the package sources
+// found in the current directory and then runs the resulting test binary.
+// In this mode, the test binary runs with standard output and standard error
+// connected directly to the go command's own standard output and standard
+// error, and test result caching (discussed below) is disabled.
+// After the package test finishes, go test prints to standard output a
+// summary line showing the test status ('ok' or 'FAIL'), package name,
+// and elapsed time.
+//
+// In package list mode, go test compiles and tests each of the packages
+// listed on the command line. If a package test passes, go test prints only
+// the final 'ok' summary line. If a package test fails, go test prints the
+// full test output. If invoked with the -bench or -v flag, go test prints
+// the full output even for passing package tests, in order to display the
+// requested benchmark results or verbose logging. In package list mode,
+// go test prints all test output and summary lines to standard output.
+//
+// In package list mode, go test also caches successful package test results.
+// If go test has cached a previous test run using the same test binary and
+// the same command line consisting entirely of cacheable test flags
+// (defined as -cpu, -list, -parallel, -run, -short, and -v),
+// go test will redisplay the previous output instead of running the test
+// binary again. In the summary line, go test prints '(cached)' in place of
+// the elapsed time. To disable test caching, use any test flag or argument
+// other than the cacheable flags. The idiomatic way to disable test caching
+// explicitly is to use -count=1.
 //
 // In addition to the build flags, the flags handled by 'go test' itself are:
 //

src/cmd/go/go_test.go

@@ -4741,3 +4741,96 @@ func TestBuildCache(t *testing.T) {
 	tg.grepStderr(`[\\/]link|gccgo`, "did not run linker")
 
 }
+
+func TestTestCache(t *testing.T) {
+	if strings.Contains(os.Getenv("GODEBUG"), "gocacheverify") {
+		t.Skip("GODEBUG gocacheverify")
+	}
+	tg := testgo(t)
+	defer tg.cleanup()
+	tg.makeTempdir()
+	tg.setenv("GOPATH", tg.tempdir)
+	tg.setenv("GOCACHE", filepath.Join(tg.tempdir, "cache"))
+
+	tg.run("test", "-x", "errors")
+	tg.grepStderr(`[\\/]compile|gccgo`, "did not run compiler")
+	tg.grepStderr(`[\\/]link|gccgo`, "did not run linker")
+	tg.grepStderr(`errors\.test`, "did not run test")
+
+	tg.run("test", "-x", "errors")
+	tg.grepStdout(`ok  \terrors\t\(cached\)`, "did not report cached result")
+	tg.grepStderrNot(`[\\/]compile|gccgo`, "incorrectly ran compiler")
+	tg.grepStderrNot(`[\\/]link|gccgo`, "incorrectly ran linker")
+	tg.grepStderrNot(`errors\.test`, "incorrectly ran test")
+	tg.grepStderrNot("DO NOT USE", "poisoned action status leaked")
+
+	// The -p=1 in the commands below just makes the -x output easier to read.
+
+	t.Log("\n\nINITIAL\n\n")
+
+	tg.tempFile("src/p1/p1.go", "package p1\nvar X =  1\n")
+	tg.tempFile("src/p2/p2.go", "package p2\nimport _ \"p1\"\nvar X = 1\n")
+	tg.tempFile("src/t/t1/t1_test.go", "package t\nimport \"testing\"\nfunc Test1(*testing.T) {}\n")
+	tg.tempFile("src/t/t2/t2_test.go", "package t\nimport _ \"p1\"\nimport \"testing\"\nfunc Test2(*testing.T) {}\n")
+	tg.tempFile("src/t/t3/t3_test.go", "package t\nimport \"p1\"\nimport \"testing\"\nfunc Test3(t *testing.T) {t.Log(p1.X)}\n")
+	tg.tempFile("src/t/t4/t4_test.go", "package t\nimport \"p2\"\nimport \"testing\"\nfunc Test4(t *testing.T) {t.Log(p2.X)}")
+	tg.run("test", "-x", "-v", "-short", "t/...")
+
+	t.Log("\n\nREPEAT\n\n")
+
+	tg.run("test", "-x", "-v", "-short", "t/...")
+	tg.grepStdout(`ok  \tt/t1\t\(cached\)`, "did not cache t1")
+	tg.grepStdout(`ok  \tt/t2\t\(cached\)`, "did not cache t2")
+	tg.grepStdout(`ok  \tt/t3\t\(cached\)`, "did not cache t3")
+	tg.grepStdout(`ok  \tt/t4\t\(cached\)`, "did not cache t4")
+	tg.grepStderrNot(`[\\/]compile|gccgo`, "incorrectly ran compiler")
+	tg.grepStderrNot(`[\\/]link|gccgo`, "incorrectly ran linker")
+	tg.grepStderrNot(`p[0-9]\.test`, "incorrectly ran test")
+
+	t.Log("\n\nCOMMENT\n\n")
+
+	// Changing the program text without affecting the compiled package
+	// should result in the package being rebuilt but nothing more.
+	tg.tempFile("src/p1/p1.go", "package p1\nvar X = 01\n")
+	tg.run("test", "-p=1", "-x", "-v", "-short", "t/...")
+	tg.grepStdout(`ok  \tt/t1\t\(cached\)`, "did not cache t1")
+	tg.grepStdout(`ok  \tt/t2\t\(cached\)`, "did not cache t2")
+	tg.grepStdout(`ok  \tt/t3\t\(cached\)`, "did not cache t3")
+	tg.grepStdout(`ok  \tt/t4\t\(cached\)`, "did not cache t4")
+	tg.grepStderrNot(`([\\/]compile|gccgo).*t[0-9]_test\.go`, "incorrectly ran compiler")
+	tg.grepStderrNot(`[\\/]link|gccgo`, "incorrectly ran linker")
+	tg.grepStderrNot(`t[0-9]\.test.*test\.short`, "incorrectly ran test")
+
+	t.Log("\n\nCHANGE\n\n")
+
+	// Changing the actual package should have limited effects.
+	tg.tempFile("src/p1/p1.go", "package p1\nvar X = 02\n")
+	tg.run("test", "-p=1", "-x", "-v", "-short", "t/...")
+
+	// p2 should have been rebuilt.
+	tg.grepStderr(`([\\/]compile|gccgo).*p2.go`, "did not recompile p2")
+
+	// t1 does not import anything, should not have been rebuilt.
+	tg.grepStderrNot(`([\\/]compile|gccgo).*t1_test.go`, "incorrectly recompiled t1")
+	tg.grepStderrNot(`([\\/]link|gccgo).*t1_test`, "incorrectly relinked t1_test")
+	tg.grepStdout(`ok  \tt/t1\t\(cached\)`, "did not cache t/t1")
+
+	// t2 imports p1 and must be rebuilt and relinked,
+	// but the change should not have any effect on the test binary,
+	// so the test should not have been rerun.
+	tg.grepStderr(`([\\/]compile|gccgo).*t2_test.go`, "did not recompile t2")
+	tg.grepStderr(`([\\/]link|gccgo).*t2\.test`, "did not relink t2_test")
+	tg.grepStdout(`ok  \tt/t2\t\(cached\)`, "did not cache t/t2")
+
+	// t3 imports p1, and changing X changes t3's test binary.
+	tg.grepStderr(`([\\/]compile|gccgo).*t3_test.go`, "did not recompile t3")
+	tg.grepStderr(`([\\/]link|gccgo).*t3\.test`, "did not relink t3_test")
+	tg.grepStderr(`t3\.test.*-test.short`, "did not rerun t3_test")
+	tg.grepStdoutNot(`ok  \tt/t3\t\(cached\)`, "reported cached t3_test result")
+
+	// t4 imports p2, but p2 did not change, so t4 should be relinked, not recompiled,
+	// and not rerun.
+	tg.grepStderrNot(`([\\/]compile|gccgo).*t4_test.go`, "incorrectly recompiled t4")
+	tg.grepStderr(`([\\/]link|gccgo).*t4\.test`, "did not relink t4_test")
+	tg.grepStdout(`ok  \tt/t4\t\(cached\)`, "did not cache t/t4")
+}

src/cmd/go/internal/work/action.go

@@ -68,6 +68,8 @@ type Action struct {
 
 	triggers []*Action // inverse of deps
 
+	TryCache func(*Builder, *Action) bool // callback for cache bypass
+
 	// Generated files, directories.
 	Objdir   string         // directory for intermediate objects
 	Target   string         // goal of the action: the created package or executable
@@ -84,6 +86,15 @@ type Action struct {
 	Failed   bool // whether the action failed
 }
 
+// BuildActionID returns the action ID section of a's build ID.
+func (a *Action) BuildActionID() string { return actionID(a.buildID) }
+
+// BuildContentID returns the content ID section of a's build ID.
+func (a *Action) BuildContentID() string { return contentID(a.buildID) }
+
+// BuildID returns a's build ID.
+func (a *Action) BuildID() string { return a.buildID }
+
 // An actionQueue is a priority queue of actions.
 type actionQueue []*Action
 

src/cmd/go/internal/work/buildid.go

@@ -93,6 +93,15 @@ import (
 
 const buildIDSeparator = "/"
 
+// actionID returns the action ID half of a build ID.
+func actionID(buildID string) string {
+	i := strings.Index(buildID, buildIDSeparator)
+	if i < 0 {
+		return buildID
+	}
+	return buildID[:i]
+}
+
 // contentID returns the content ID half of a build ID.
 func contentID(buildID string) string {
 	return buildID[strings.LastIndex(buildID, buildIDSeparator)+1:]
@@ -276,6 +285,7 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID
 	// want the package for is to link a binary, and the binary is
 	// already up-to-date, then to avoid a rebuild, report the package
 	// as up-to-date as well. See "Build IDs" comment above.
+	// TODO(rsc): Rewrite this code to use a TryCache func on the link action.
 	if target != "" && !cfg.BuildA && a.Mode == "build" && len(a.triggers) == 1 && a.triggers[0].Mode == "link" {
 		buildID, err := buildid.ReadFile(target)
 		if err == nil {
@@ -306,6 +316,17 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID
 		}
 	}
 
+	// Special case for linking a test binary: if the only thing we
+	// want the binary for is to run the test, and the test result is cached,
+	// then to avoid the link step, report the link as up-to-date.
+	// We avoid the nested build ID problem in the previous special case
+	// by recording the test results in the cache under the action ID half.
+	if !cfg.BuildA && len(a.triggers) == 1 && a.triggers[0].TryCache != nil && a.triggers[0].TryCache(b, a.triggers[0]) {
+		a.Target = "DO NOT USE -  pseudo-cache Target"
+		a.built = "DO NOT USE - pseudo-cache built"
+		return true
+	}
+
 	if b.ComputeStaleOnly {
 		// Invoked during go list only to compute and record staleness.
 		if p := a.Package; p != nil && !p.Stale {
@@ -358,9 +379,11 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID
 // a.buildID to record as the build ID in the resulting package or binary.
 // updateBuildID computes the final content ID and updates the build IDs
 // in the binary.
-func (b *Builder) updateBuildID(a *Action, target string) error {
+func (b *Builder) updateBuildID(a *Action, target string, rewrite bool) error {
 	if cfg.BuildX || cfg.BuildN {
-		b.Showcmd("", "%s # internal", joinUnambiguously(str.StringList(base.Tool("buildid"), "-w", target)))
+		if rewrite {
+			b.Showcmd("", "%s # internal", joinUnambiguously(str.StringList(base.Tool("buildid"), "-w", target)))
+		}
 		if cfg.BuildN {
 			return nil
 		}
@@ -387,17 +410,20 @@ func (b *Builder) updateBuildID(a *Action, target string) error {
 		// Assume the user specified -buildid= to override what we were going to choose.
 		return nil
 	}
-	w, err := os.OpenFile(target, os.O_WRONLY, 0)
-	if err != nil {
-		return err
-	}
-	err = buildid.Rewrite(w, matches, newID)
-	if err != nil {
-		w.Close()
-		return err
-	}
-	if err := w.Close(); err != nil {
-		return err
+
+	if rewrite {
+		w, err := os.OpenFile(target, os.O_WRONLY, 0)
+		if err != nil {
+			return err
+		}
+		err = buildid.Rewrite(w, matches, newID)
+		if err != nil {
+			w.Close()
+			return err
+		}
+		if err := w.Close(); err != nil {
+			return err
+		}
 	}
 
 	// Cache package builds, but not binaries (link steps).
@@ -408,6 +434,11 @@ func (b *Builder) updateBuildID(a *Action, target string) error {
 	// Not caching the link step also makes sure that repeated "go run" at least
 	// always rerun the linker, so that they don't get too fast.
 	// (We don't want people thinking go is a scripting language.)
+	// Note also that if we start caching binaries, then we will
+	// copy the binaries out of the cache to run them, and then
+	// that will mean the go process is itself writing a binary
+	// and then executing it, so we will need to defend against
+	// ETXTBSY problems as discussed in exec.go and golang.org/issue/22220.
 	if c := cache.Default(); c != nil && a.Mode == "build" {
 		r, err := os.Open(target)
 		if err == nil {

src/cmd/go/internal/work/exec.go

@@ -244,7 +244,7 @@ func (b *Builder) buildActionID(a *Action) cache.ActionID {
 	for _, a1 := range a.Deps {
 		p1 := a1.Package
 		if p1 != nil {
-			fmt.Fprintf(h, "import %s %s\n", p1.ImportPath, a1.buildID)
+			fmt.Fprintf(h, "import %s %s\n", p1.ImportPath, contentID(a1.buildID))
 		}
 	}
 
@@ -613,7 +613,7 @@ func (b *Builder) build(a *Action) (err error) {
 		}
 	}
 
-	if err := b.updateBuildID(a, objpkg); err != nil {
+	if err := b.updateBuildID(a, objpkg, true); err != nil {
 		return err
 	}
 
@@ -765,21 +765,23 @@ func (b *Builder) link(a *Action) (err error) {
 	}
 
 	// Update the binary with the final build ID.
-	// But if OmitDebug is set, don't, because we set OmitDebug
+	// But if OmitDebug is set, don't rewrite the binary, because we set OmitDebug
 	// on binaries that we are going to run and then delete.
 	// There's no point in doing work on such a binary.
 	// Worse, opening the binary for write here makes it
 	// essentially impossible to safely fork+exec due to a fundamental
 	// incompatibility between ETXTBSY and threads on modern Unix systems.
 	// See golang.org/issue/22220.
+	// We still call updateBuildID to update a.buildID, which is important
+	// for test result caching, but passing rewrite=false (final arg)
+	// means we don't actually rewrite the binary, nor store the
+	// result into the cache.
 	// Not calling updateBuildID means we also don't insert these
 	// binaries into the build object cache. That's probably a net win:
 	// less cache space wasted on large binaries we are not likely to
 	// need again. (On the other hand it does make repeated go test slower.)
-	if !a.Package.Internal.OmitDebug {
-		if err := b.updateBuildID(a, a.Target); err != nil {
-			return err
-		}
+	if err := b.updateBuildID(a, a.Target, !a.Package.Internal.OmitDebug); err != nil {
+		return err
 	}
 
 	a.built = a.Target