]> Cypherpunks repositories - gostls13.git/commitdiff
cmd/go: add more information to -debug-actiongraph
authorRuss Cox <rsc@golang.org>
Fri, 10 May 2019 01:29:24 +0000 (21:29 -0400)
committerRuss Cox <rsc@golang.org>
Thu, 16 May 2019 03:24:58 +0000 (03:24 +0000)
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 <rsc@golang.org>
Reviewed-by: Bryan C. Mills <bcmills@google.com>
src/cmd/go/internal/work/action.go
src/cmd/go/internal/work/buildid.go
src/cmd/go/internal/work/exec.go
src/cmd/go/internal/work/gc.go
src/cmd/go/internal/work/gccgo.go

index f17137e6668d766be26c025a943304c0d50eeba6..ec9f8583d2d96a6e1a1ea32195fca8d34ab0aa5e 100644 (file)
@@ -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")
index 894c260b29afdb3421414e443758c91f8fa96645..1a98980915167c3b889261e9ee2ed833335bdc2f 100644 (file)
@@ -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
index b655751fb6c943d311dfe912f2a8c737ecb77f5d..35e70ddb1e042550ca56c402f439d62cec7a0fcf 100644 (file)
@@ -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")) {
index e7d5fae4de7742aa86832d9e9d102c561e686902..6ec24b28555dd63ed83eb3b3e7bd0d624114c893 100644 (file)
@@ -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
 }
 
index ff2621e1c4963f0c5f33ab083851e9e364992e37..67065950b206716e13c0bcbbee9201109ff77512 100644 (file)
@@ -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
 }