cmd/go: cache and replay command output during build

It's nice that

	go build -gcflags=-m errors
	go build -gcflags=-m errors

uses the cache for the second command.

Even nicer is to make the second command
print the same output as the first command.

Fixes #22587.

Change-Id: I64350839f01c86c9a095d9d22f6924cd7a0b9105
Reviewed-on: https://go-review.googlesource.com/77110Reviewed-by: Ian Lance Taylor <iant@golang.org>

src/cmd/go/go_test.go

@@ -4803,6 +4803,32 @@ func TestBuildCache(t *testing.T) {
 	tg.grepStderr(`[\\/]link|gccgo`, "did not run linker")
 }
 
+func TestCacheOutput(t *testing.T) {
+	// Test that command output is cached and replayed too.
+	if strings.Contains(os.Getenv("GODEBUG"), "gocacheverify") {
+		t.Skip("GODEBUG gocacheverify")
+	}
+	tg := testgo(t)
+	defer tg.cleanup()
+	tg.parallel()
+	tg.setenv("GOPATH", filepath.Join(tg.pwd(), "testdata"))
+	tg.makeTempdir()
+	tg.setenv("GOCACHE", tg.tempdir)
+
+	tg.run("build", "-gcflags=-m", "errors")
+	stdout1 := tg.getStdout()
+	stderr1 := tg.getStderr()
+
+	tg.run("build", "-gcflags=-m", "errors")
+	stdout2 := tg.getStdout()
+	stderr2 := tg.getStderr()
+
+	if stdout2 != stdout1 || stderr2 != stderr1 {
+		t.Errorf("cache did not reproduce output:\n\nstdout1:\n%s\n\nstdout2:\n%s\n\nstderr1:\n%s\n\nstderr2:\n%s",
+			stdout1, stdout2, stderr1, stderr2)
+	}
+}
+
 func TestIssue22588(t *testing.T) {
 	// Don't get confused by stderr coming from tools.
 	tg := testgo(t)

src/cmd/go/internal/cache/hash.go

@@ -38,6 +38,26 @@ type Hash struct {
 // which are still addressed by unsalted SHA256.
 var hashSalt = []byte(runtime.Version())
 
+// Subkey returns an action ID corresponding to mixing a parent
+// action ID with a string description of the subkey.
+func Subkey(parent ActionID, desc string) ActionID {
+	h := sha256.New()
+	h.Write([]byte("subkey:"))
+	h.Write(parent[:])
+	h.Write([]byte(desc))
+	var out ActionID
+	h.Sum(out[:0])
+	if debugHash {
+		fmt.Fprintf(os.Stderr, "HASH subkey %x %q = %x\n", parent, desc, out)
+	}
+	if verify {
+		hashDebug.Lock()
+		hashDebug.m[out] = fmt.Sprintf("subkey %x %q", parent, desc)
+		hashDebug.Unlock()
+	}
+	return out
+}
+
 // NewHash returns a new Hash.
 // The caller is expected to Write data to it and then call Sum.
 func NewHash(name string) *Hash {

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

@@ -81,6 +81,7 @@ type Action struct {
 
 	needVet bool       // Mode=="build": need to fill in vet config
 	vetCfg  *vetConfig // vet config
+	output  []byte     // output redirect buffer (nil means use b.Print)
 
 	// Execution state.
 	pending  int  // number of deps yet to complete

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

@@ -244,6 +244,10 @@ func (b *Builder) fileHash(file string) string {
 // and returns false. When useCache returns false the expectation is that
 // the caller will build the target and then call updateBuildID to finish the
 // build ID computation.
+// When useCache returns false, it may have initiated buffering of output
+// during a's work. The caller should defer b.flushOutput(a), to make sure
+// that flushOutput is eventually called regardless of whether the action
+// succeeds. The flushOutput call must happen after updateBuildID.
 func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID, target string) bool {
 	// The second half of the build ID here is a placeholder for the content hash.
 	// It's important that the overall buildID be unlikely verging on impossible
@@ -358,26 +362,47 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID
 	// We treat hits in this cache as being "stale" for the purposes of go list
 	// (in effect, "stale" means whether p.Target is up-to-date),
 	// but we're still happy to use results from the build artifact cache.
-	if !cfg.BuildA {
-		if c := cache.Default(); c != nil {
+	if c := cache.Default(); c != nil {
+		if !cfg.BuildA {
 			outputID, size, err := c.Get(actionHash)
 			if err == nil {
 				file := c.OutputFile(outputID)
 				info, err1 := os.Stat(file)
 				buildID, err2 := buildid.ReadFile(file)
 				if err1 == nil && err2 == nil && info.Size() == size {
-					a.built = file
-					a.Target = "DO NOT USE - using cache"
-					a.buildID = buildID
-					return true
+					stdout, err := c.GetBytes(cache.Subkey(a.actionID, "stdout"))
+					if err == nil {
+						if len(stdout) > 0 {
+							if cfg.BuildX || cfg.BuildN {
+								id, _, _ := c.Get(cache.Subkey(a.actionID, "stdout"))
+								b.Showcmd("", "%s  # internal", joinUnambiguously(str.StringList("cat", c.OutputFile(id))))
+							}
+							if !cfg.BuildN {
+								b.Print(string(stdout))
+							}
+						}
+						a.built = file
+						a.Target = "DO NOT USE - using cache"
+						a.buildID = buildID
+						return true
+					}
 				}
 			}
 		}
+
+		// Begin saving output for later writing to cache.
+		a.output = []byte{}
 	}
 
 	return false
 }
 
+// flushOutput flushes the output being queued in a.
+func (b *Builder) flushOutput(a *Action) {
+	b.Print(string(a.output))
+	a.output = nil
+}
+
 // updateBuildID updates the build ID in the target written by action a.
 // It requires that useCache was called for action a and returned false,
 // and that the build was then carried out and given the temporary
@@ -447,7 +472,11 @@ func (b *Builder) updateBuildID(a *Action, target string, rewrite bool) error {
 	if c := cache.Default(); c != nil && a.Mode == "build" {
 		r, err := os.Open(target)
 		if err == nil {
+			if a.output == nil {
+				panic("internal error: a.output not set")
+			}
 			c.Put(a.actionID, r)
+			c.PutBytes(cache.Subkey(a.actionID, "stdout"), a.output)
 			r.Close()
 		}
 	}

src/cmd/go/internal/work/gc.go

@@ -225,8 +225,8 @@ func (gcToolchain) asm(b *Builder, a *Action, sfiles []string) ([]string, error)
 	for _, sfile := range sfiles {
 		ofile := a.Objdir + sfile[:len(sfile)-len(".s")] + ".o"
 		ofiles = append(ofiles, ofile)
-		a := append(args, "-o", ofile, mkAbs(p.Dir, sfile))
-		if err := b.run(p.Dir, p.ImportPath, nil, a...); err != nil {
+		args1 := append(args, "-o", ofile, mkAbs(p.Dir, sfile))
+		if err := b.run(a, p.Dir, p.ImportPath, nil, args1...); err != nil {
 			return nil, err
 		}
 	}
@@ -236,12 +236,12 @@ func (gcToolchain) asm(b *Builder, a *Action, sfiles []string) ([]string, error)
 // toolVerify checks that the command line args writes the same output file
 // if run using newTool instead.
 // Unused now but kept around for future use.
-func toolVerify(b *Builder, p *load.Package, newTool string, ofile string, args []interface{}) error {
+func toolVerify(a *Action, b *Builder, p *load.Package, newTool string, ofile string, args []interface{}) error {
 	newArgs := make([]interface{}, len(args))
 	copy(newArgs, args)
 	newArgs[1] = base.Tool(newTool)
 	newArgs[3] = ofile + ".new" // x.6 becomes x.6.new
-	if err := b.run(p.Dir, p.ImportPath, nil, newArgs...); err != nil {
+	if err := b.run(a, p.Dir, p.ImportPath, nil, newArgs...); err != nil {
 		return err
 	}
 	data1, err := ioutil.ReadFile(ofile)
@@ -283,7 +283,7 @@ func (gcToolchain) pack(b *Builder, a *Action, afile string, ofiles []string) er
 		return nil
 	}
 	if err := packInternal(b, absAfile, absOfiles); err != nil {
-		b.showOutput(p.Dir, p.ImportPath, err.Error()+"\n")
+		b.showOutput(a, p.Dir, p.ImportPath, err.Error()+"\n")
 		return errPrintedOutput
 	}
 	return nil
@@ -454,7 +454,7 @@ func (gcToolchain) ld(b *Builder, root *Action, out, importcfg, mainpkg string)
 		dir, out = filepath.Split(out)
 	}
 
-	return b.run(dir, root.Package.ImportPath, nil, cfg.BuildToolexec, base.Tool("link"), "-o", out, "-importcfg", importcfg, ldflags, mainpkg)
+	return b.run(root, dir, root.Package.ImportPath, nil, cfg.BuildToolexec, base.Tool("link"), "-o", out, "-importcfg", importcfg, ldflags, mainpkg)
 }
 
 func (gcToolchain) ldShared(b *Builder, root *Action, toplevelactions []*Action, out, importcfg string, allactions []*Action) error {
@@ -485,7 +485,7 @@ func (gcToolchain) ldShared(b *Builder, root *Action, toplevelactions []*Action,
 		}
 		ldflags = append(ldflags, d.Package.ImportPath+"="+d.Target)
 	}
-	return b.run(".", out, nil, cfg.BuildToolexec, base.Tool("link"), "-o", out, "-importcfg", importcfg, ldflags)
+	return b.run(root, ".", out, nil, cfg.BuildToolexec, base.Tool("link"), "-o", out, "-importcfg", importcfg, ldflags)
 }
 
 func (gcToolchain) cc(b *Builder, a *Action, ofile, cfile string) error {

src/cmd/go/internal/work/gccgo.go

@@ -163,7 +163,7 @@ func (tools gccgoToolchain) asm(b *Builder, a *Action, sfiles []string) ([]strin
 		}
 		defs = tools.maybePIC(defs)
 		defs = append(defs, b.gccArchArgs()...)
-		err := b.run(p.Dir, p.ImportPath, nil, tools.compiler(), "-xassembler-with-cpp", "-I", a.Objdir, "-c", "-o", ofile, defs, sfile)
+		err := b.run(a, p.Dir, p.ImportPath, nil, tools.compiler(), "-xassembler-with-cpp", "-I", a.Objdir, "-c", "-o", ofile, defs, sfile)
 		if err != nil {
 			return nil, err
 		}
@@ -185,7 +185,7 @@ func (gccgoToolchain) pack(b *Builder, a *Action, afile string, ofiles []string)
 	for _, f := range ofiles {
 		absOfiles = append(absOfiles, mkAbs(objdir, f))
 	}
-	return b.run(p.Dir, p.ImportPath, nil, "ar", "rc", mkAbs(objdir, afile), absOfiles)
+	return b.run(a, p.Dir, p.ImportPath, nil, "ar", "rc", mkAbs(objdir, afile), absOfiles)
 }
 
 func (tools gccgoToolchain) link(b *Builder, root *Action, out, importcfg string, allactions []*Action, buildmode, desc string) error {
@@ -245,11 +245,11 @@ func (tools gccgoToolchain) link(b *Builder, root *Action, out, importcfg string
 				return "", nil
 			}
 		}
-		err := b.run(root.Objdir, desc, nil, "ar", "x", newArchive, "_cgo_flags")
+		err := b.run(root, root.Objdir, desc, nil, "ar", "x", newArchive, "_cgo_flags")
 		if err != nil {
 			return "", err
 		}
-		err = b.run(".", desc, nil, "ar", "d", newArchive, "_cgo_flags")
+		err = b.run(root, ".", desc, nil, "ar", "d", newArchive, "_cgo_flags")
 		if err != nil {
 			return "", err
 		}
@@ -427,13 +427,13 @@ func (tools gccgoToolchain) link(b *Builder, root *Action, out, importcfg string
 		}
 	}
 
-	if err := b.run(".", desc, nil, tools.linker(), "-o", out, ldflags, forcedGccgoflags, root.Package.Internal.Gccgoflags); err != nil {
+	if err := b.run(root, ".", desc, nil, tools.linker(), "-o", out, ldflags, forcedGccgoflags, root.Package.Internal.Gccgoflags); err != nil {
 		return err
 	}
 
 	switch buildmode {
 	case "c-archive":
-		if err := b.run(".", desc, nil, "ar", "rc", realOut, out); err != nil {
+		if err := b.run(root, ".", desc, nil, "ar", "rc", realOut, out); err != nil {
 			return err
 		}
 	}
@@ -464,7 +464,7 @@ func (tools gccgoToolchain) cc(b *Builder, a *Action, ofile, cfile string) error
 		defs = append(defs, "-fsplit-stack")
 	}
 	defs = tools.maybePIC(defs)
-	return b.run(p.Dir, p.ImportPath, nil, envList("CC", cfg.DefaultCC(cfg.Goos, cfg.Goarch)), "-Wall", "-g",
+	return b.run(a, p.Dir, p.ImportPath, nil, envList("CC", cfg.DefaultCC(cfg.Goos, cfg.Goarch)), "-Wall", "-g",
 		"-I", a.Objdir, "-I", inc, "-o", ofile, defs, "-c", cfile)
 }