From: Russ Cox Date: Fri, 10 May 2019 01:29:24 +0000 (-0400) Subject: cmd/go: add more information to -debug-actiongraph X-Git-Tag: go1.13beta1~283 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=54260c570f1202b992b7b6ee8f837dd717927d24;p=gostls13.git cmd/go: add more information to -debug-actiongraph Add information about action and build IDs, commands run, time spent in commands, and overall time to -debug-actiongraph output. Also avoid a terrible outcome in: go build -debug-actiongraph x.go Change-Id: I7a3a638f4848d75f2bdc997517f4ab23656da4f1 Reviewed-on: https://go-review.googlesource.com/c/go/+/177138 Run-TryBot: Russ Cox Reviewed-by: Bryan C. Mills --- diff --git a/src/cmd/go/internal/work/action.go b/src/cmd/go/internal/work/action.go index f17137e666..ec9f8583d2 100644 --- a/src/cmd/go/internal/work/action.go +++ b/src/cmd/go/internal/work/action.go @@ -91,9 +91,10 @@ type Action struct { output []byte // output redirect buffer (nil means use b.Print) // Execution state. - pending int // number of deps yet to complete - priority int // relative execution priority - Failed bool // whether the action failed + pending int // number of deps yet to complete + priority int // relative execution priority + Failed bool // whether the action failed + json *actionJSON // action graph information } // BuildActionID returns the action ID section of a's build ID. @@ -125,6 +126,9 @@ func (q *actionQueue) Pop() interface{} { } func (q *actionQueue) push(a *Action) { + if a.json != nil { + a.json.TimeReady = time.Now() + } heap.Push(q, a) } @@ -136,16 +140,28 @@ type actionJSON struct { ID int Mode string Package string - Deps []int `json:",omitempty"` - IgnoreFail bool `json:",omitempty"` - Args []string `json:",omitempty"` - Link bool `json:",omitempty"` - Objdir string `json:",omitempty"` - Target string `json:",omitempty"` - Priority int `json:",omitempty"` - Failed bool `json:",omitempty"` - Built string `json:",omitempty"` - VetxOnly bool `json:",omitempty"` + Deps []int `json:",omitempty"` + IgnoreFail bool `json:",omitempty"` + Args []string `json:",omitempty"` + Link bool `json:",omitempty"` + Objdir string `json:",omitempty"` + Target string `json:",omitempty"` + Priority int `json:",omitempty"` + Failed bool `json:",omitempty"` + Built string `json:",omitempty"` + VetxOnly bool `json:",omitempty"` + NeedVet bool `json:",omitempty"` + NeedBuild bool `json:",omitempty"` + ActionID string `json:",omitempty"` + BuildID string `json:",omitempty"` + TimeReady time.Time `json:",omitempty"` + TimeStart time.Time `json:",omitempty"` + TimeDone time.Time `json:",omitempty"` + + Cmd []string // `json:",omitempty"` + CmdReal time.Duration `json:",omitempty"` + CmdUser time.Duration `json:",omitempty"` + CmdSys time.Duration `json:",omitempty"` } // cacheKey is the key for the action cache. @@ -175,26 +191,30 @@ func actionGraphJSON(a *Action) string { var list []*actionJSON for id, a := range workq { - aj := &actionJSON{ - Mode: a.Mode, - ID: id, - IgnoreFail: a.IgnoreFail, - Args: a.Args, - Objdir: a.Objdir, - Target: a.Target, - Failed: a.Failed, - Priority: a.priority, - Built: a.built, - VetxOnly: a.VetxOnly, - } - if a.Package != nil { - // TODO(rsc): Make this a unique key for a.Package somehow. - aj.Package = a.Package.ImportPath - } - for _, a1 := range a.Deps { - aj.Deps = append(aj.Deps, inWorkq[a1]) + if a.json == nil { + a.json = &actionJSON{ + Mode: a.Mode, + ID: id, + IgnoreFail: a.IgnoreFail, + Args: a.Args, + Objdir: a.Objdir, + Target: a.Target, + Failed: a.Failed, + Priority: a.priority, + Built: a.built, + VetxOnly: a.VetxOnly, + NeedBuild: a.needBuild, + NeedVet: a.needVet, + } + if a.Package != nil { + // TODO(rsc): Make this a unique key for a.Package somehow. + a.json.Package = a.Package.ImportPath + } + for _, a1 := range a.Deps { + a.json.Deps = append(a.json.Deps, inWorkq[a1]) + } } - list = append(list, aj) + list = append(list, a.json) } js, err := json.MarshalIndent(list, "", "\t") diff --git a/src/cmd/go/internal/work/buildid.go b/src/cmd/go/internal/work/buildid.go index 894c260b29..1a98980915 100644 --- a/src/cmd/go/internal/work/buildid.go +++ b/src/cmd/go/internal/work/buildid.go @@ -423,6 +423,9 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID // engineered 96-bit partial SHA256 collision. a.actionID = actionHash actionID := hashToString(actionHash) + if a.json != nil { + a.json.ActionID = actionID + } contentID := actionID // temporary placeholder, likely unique a.buildID = actionID + buildIDSeparator + contentID @@ -440,6 +443,9 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID buildID, _ = buildid.ReadFile(target) if strings.HasPrefix(buildID, actionID+buildIDSeparator) { a.buildID = buildID + if a.json != nil { + a.json.BuildID = a.buildID + } a.built = target // Poison a.Target to catch uses later in the build. a.Target = "DO NOT USE - " + a.Mode @@ -482,6 +488,9 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID // Poison a.Target to catch uses later in the build. a.Target = "DO NOT USE - main build pseudo-cache Target" a.built = "DO NOT USE - main build pseudo-cache built" + if a.json != nil { + a.json.BuildID = a.buildID + } return true } // Otherwise restore old build ID for main build. @@ -549,6 +558,9 @@ func (b *Builder) useCache(a *Action, p *load.Package, actionHash cache.ActionID a.built = file a.Target = "DO NOT USE - using cache" a.buildID = buildID + if a.json != nil { + a.json.BuildID = a.buildID + } if p := a.Package; p != nil { // Clearer than explaining that something else is stale. p.StaleReason = "not installed but available in build cache" @@ -644,6 +656,9 @@ func (b *Builder) updateBuildID(a *Action, target string, rewrite bool) error { // Replace with new content-based ID. a.buildID = newID + if a.json != nil { + a.json.BuildID = a.buildID + } if len(matches) == 0 { // Assume the user specified -buildid= to override what we were going to choose. return nil diff --git a/src/cmd/go/internal/work/exec.go b/src/cmd/go/internal/work/exec.go index b655751fb6..35e70ddb1e 100644 --- a/src/cmd/go/internal/work/exec.go +++ b/src/cmd/go/internal/work/exec.go @@ -75,13 +75,22 @@ func (b *Builder) Do(root *Action) { a.priority = i } - if cfg.DebugActiongraph != "" { - js := actionGraphJSON(root) - if err := ioutil.WriteFile(cfg.DebugActiongraph, []byte(js), 0666); err != nil { - fmt.Fprintf(os.Stderr, "go: writing action graph: %v\n", err) - base.SetExitStatus(1) + // Write action graph, without timing information, in case we fail and exit early. + writeActionGraph := func() { + if file := cfg.DebugActiongraph; file != "" { + if strings.HasSuffix(file, ".go") { + // Do not overwrite Go source code in: + // go build -debug-actiongraph x.go + base.Fatalf("go: refusing to write action graph to %v\n", file) + } + js := actionGraphJSON(root) + if err := ioutil.WriteFile(file, []byte(js), 0666); err != nil { + fmt.Fprintf(os.Stderr, "go: writing action graph: %v\n", err) + base.SetExitStatus(1) + } } } + writeActionGraph() b.readySema = make(chan bool, len(all)) @@ -100,11 +109,16 @@ func (b *Builder) Do(root *Action) { // Handle runs a single action and takes care of triggering // any actions that are runnable as a result. handle := func(a *Action) { + if a.json != nil { + a.json.TimeStart = time.Now() + } var err error - if a.Func != nil && (!a.Failed || a.IgnoreFail) { err = a.Func(b, a) } + if a.json != nil { + a.json.TimeDone = time.Now() + } // The actions run in parallel but all the updates to the // shared work state are serialized through b.exec. @@ -170,6 +184,9 @@ func (b *Builder) Do(root *Action) { } wg.Wait() + + // Write action graph again, this time with timing information. + writeActionGraph() } // buildActionID computes the action ID for a build action. @@ -1322,7 +1339,7 @@ func (b *Builder) getPkgConfigFlags(p *load.Package) (cflags, ldflags []string, } } var out []byte - out, err = b.runOut(p.Dir, nil, b.PkgconfigCmd(), "--cflags", pcflags, "--", pkgs) + out, err = b.runOut(nil, p.Dir, nil, b.PkgconfigCmd(), "--cflags", pcflags, "--", pkgs) if err != nil { b.showOutput(nil, p.Dir, b.PkgconfigCmd()+" --cflags "+strings.Join(pcflags, " ")+" -- "+strings.Join(pkgs, " "), string(out)) b.Print(err.Error() + "\n") @@ -1337,7 +1354,7 @@ func (b *Builder) getPkgConfigFlags(p *load.Package) (cflags, ldflags []string, return nil, nil, err } } - out, err = b.runOut(p.Dir, nil, b.PkgconfigCmd(), "--libs", pcflags, "--", pkgs) + out, err = b.runOut(nil, p.Dir, nil, b.PkgconfigCmd(), "--libs", pcflags, "--", pkgs) if err != nil { b.showOutput(nil, p.Dir, b.PkgconfigCmd()+" --libs "+strings.Join(pcflags, " ")+" -- "+strings.Join(pkgs, " "), string(out)) b.Print(err.Error() + "\n") @@ -1437,6 +1454,9 @@ func BuildInstallFunc(b *Builder, a *Action) (err error) { a1 := a.Deps[0] a.buildID = a1.buildID + if a.json != nil { + a.json.BuildID = a.buildID + } // If we are using the eventual install target as an up-to-date // cached copy of the thing we built, then there's no need to @@ -1853,7 +1873,7 @@ var cgoTypeSigRe = lazyregexp.New(`\b_C2?(type|func|var|macro)_\B`) // If the command fails, run prints information about the failure // and returns a non-nil error. func (b *Builder) run(a *Action, dir string, desc string, env []string, cmdargs ...interface{}) error { - out, err := b.runOut(dir, env, cmdargs...) + out, err := b.runOut(a, dir, env, cmdargs...) if len(out) > 0 { if desc == "" { desc = b.fmtcmd(dir, "%s", strings.Join(str.StringList(cmdargs...), " ")) @@ -1885,7 +1905,8 @@ func (b *Builder) processOutput(out []byte) string { // runOut runs the command given by cmdline in the directory dir. // It returns the command output and any errors that occurred. -func (b *Builder) runOut(dir string, env []string, cmdargs ...interface{}) ([]byte, error) { +// It accumulates execution time in a. +func (b *Builder) runOut(a *Action, dir string, env []string, cmdargs ...interface{}) ([]byte, error) { cmdline := str.StringList(cmdargs...) for _, arg := range cmdline { @@ -1926,7 +1947,17 @@ func (b *Builder) runOut(dir string, env []string, cmdargs ...interface{}) ([]by cmd.Dir = dir cmd.Env = base.EnvForDir(cmd.Dir, os.Environ()) cmd.Env = append(cmd.Env, env...) + start := time.Now() err := cmd.Run() + if a != nil && a.json != nil { + aj := a.json + aj.Cmd = append(aj.Cmd, joinUnambiguously(cmdline)) + aj.CmdReal += time.Since(start) + if ps := cmd.ProcessState; ps != nil { + aj.CmdUser += ps.UserTime() + aj.CmdSys += ps.SystemTime() + } + } // err can be something like 'exit status 1'. // Add information about what program was running. @@ -2124,7 +2155,7 @@ func (b *Builder) ccompile(a *Action, p *load.Package, outfile string, flags []s if !filepath.IsAbs(outfile) { outfile = filepath.Join(p.Dir, outfile) } - output, err := b.runOut(filepath.Dir(file), b.cCompilerEnv(), compiler, flags, "-o", outfile, "-c", filepath.Base(file)) + output, err := b.runOut(a, filepath.Dir(file), b.cCompilerEnv(), compiler, flags, "-o", outfile, "-c", filepath.Base(file)) if len(output) > 0 { // On FreeBSD 11, when we pass -g to clang 3.8 it // invokes its internal assembler with -dwarf-version=2. @@ -2157,7 +2188,7 @@ func (b *Builder) ccompile(a *Action, p *load.Package, outfile string, flags []s } // gccld runs the gcc linker to create an executable from a set of object files. -func (b *Builder) gccld(p *load.Package, objdir, outfile string, flags []string, objs []string) error { +func (b *Builder) gccld(a *Action, p *load.Package, objdir, outfile string, flags []string, objs []string) error { var cmd []string if len(p.CXXFiles) > 0 || len(p.SwigCXXFiles) > 0 { cmd = b.GxxCmd(p.Dir, objdir) @@ -2167,7 +2198,7 @@ func (b *Builder) gccld(p *load.Package, objdir, outfile string, flags []string, cmdargs := []interface{}{cmd, "-o", outfile, objs, flags} dir := p.Dir - out, err := b.runOut(dir, b.cCompilerEnv(), cmdargs...) + out, err := b.runOut(a, dir, b.cCompilerEnv(), cmdargs...) if len(out) > 0 { // Filter out useless linker warnings caused by bugs outside Go. // See also cmd/link/internal/ld's hostlink method. @@ -2651,7 +2682,7 @@ func (b *Builder) dynimport(a *Action, p *load.Package, objdir, importGo, cgoExe } ldflags = append(n, "-pie") } - if err := b.gccld(p, objdir, dynobj, ldflags, linkobj); err != nil { + if err := b.gccld(a, p, objdir, dynobj, ldflags, linkobj); err != nil { return err } @@ -2710,7 +2741,7 @@ var ( ) func (b *Builder) swigDoVersionCheck() error { - out, err := b.runOut("", nil, "swig", "-version") + out, err := b.runOut(nil, "", nil, "swig", "-version") if err != nil { return err } @@ -2865,7 +2896,7 @@ func (b *Builder) swigOne(a *Action, p *load.Package, file, objdir string, pcCFL args = append(args, "-c++") } - out, err := b.runOut(p.Dir, nil, "swig", args, file) + out, err := b.runOut(a, p.Dir, nil, "swig", args, file) if err != nil { if len(out) > 0 { if bytes.Contains(out, []byte("-intgosize")) || bytes.Contains(out, []byte("-cgo")) { diff --git a/src/cmd/go/internal/work/gc.go b/src/cmd/go/internal/work/gc.go index e7d5fae4de..6ec24b2855 100644 --- a/src/cmd/go/internal/work/gc.go +++ b/src/cmd/go/internal/work/gc.go @@ -140,7 +140,7 @@ func (gcToolchain) gc(b *Builder, a *Action, archive string, importcfg []byte, s args = append(args, mkAbs(p.Dir, f)) } - output, err = b.runOut(p.Dir, nil, args...) + output, err = b.runOut(a, p.Dir, nil, args...) return ofile, output, err } diff --git a/src/cmd/go/internal/work/gccgo.go b/src/cmd/go/internal/work/gccgo.go index ff2621e1c4..67065950b2 100644 --- a/src/cmd/go/internal/work/gccgo.go +++ b/src/cmd/go/internal/work/gccgo.go @@ -94,7 +94,7 @@ func (tools gccgoToolchain) gc(b *Builder, a *Action, archive string, importcfg args = append(args, mkAbs(p.Dir, f)) } - output, err = b.runOut(p.Dir, nil, args) + output, err = b.runOut(a, p.Dir, nil, args) return ofile, output, err }