cmd/go: add trace events for each action

This change adds a trace event for each action and also
annotates each of the action execution goroutines with trace.Goroutine
so that the actions eaxecuted by each goroutine appear on different threads in
the chrome trace viewer.

Updates #38714

Change-Id: I2e58dc5606b2e3f7f87076a61e1cc6a2014255c5
Reviewed-on: https://go-review.googlesource.com/c/go/+/248320
Run-TryBot: Michael Matloob <matloob@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Bryan C. Mills <bcmills@google.com>

diff --git a/src/cmd/go/internal/trace/trace.go b/src/cmd/go/internal/trace/trace.go
index 32ce0408f561792c786d4c32428756df1f7d4ee6..24130d9d72645f26ec2c6f1c506d18f598bf6085 100644 (file)
--- a/src/cmd/go/internal/trace/trace.go
+++ b/src/cmd/go/internal/trace/trace.go
@@ -45,10 +45,10 @@ func StartSpan(ctx context.Context, name string) (context.Context, *Span) {
        return ctx, childSpan
 }
 
-// Goroutine associates the context with a new Thread ID. The Chrome trace viewer associates each
+// StartGoroutine associates the context with a new Thread ID. The Chrome trace viewer associates each
 // trace event with a thread, and doesn't expect events with the same thread id to happen at the
 // same time.
-func Goroutine(ctx context.Context) context.Context {
+func StartGoroutine(ctx context.Context) context.Context {
        tc, ok := getTraceContext(ctx)
        if !ok {
                return ctx

diff --git a/src/cmd/go/internal/work/exec.go b/src/cmd/go/internal/work/exec.go
index 3ea3293ae18d8bfc11a6feba24f6640cbabda9a4..56a127f36fda6816a3c7c462559eb7ff6503e261 100644 (file)
--- a/src/cmd/go/internal/work/exec.go
+++ b/src/cmd/go/internal/work/exec.go
@@ -115,13 +115,21 @@ func (b *Builder) Do(ctx context.Context, root *Action) {
 
        // Handle runs a single action and takes care of triggering
        // any actions that are runnable as a result.
-       handle := func(a *Action) {
+       handle := func(ctx context.Context, a *Action) {
                if a.json != nil {
                        a.json.TimeStart = time.Now()
                }
                var err error
                if a.Func != nil && (!a.Failed || a.IgnoreFail) {
+                       // TODO(matloob): Better action descriptions
+                       desc := "Executing action "
+                       if a.Package != nil {
+                               desc += "(" + a.Mode + " " + a.Package.Desc() + ")"
+                       }
+                       ctx, span := trace.StartSpan(ctx, desc)
+                       _ = ctx
                        err = a.Func(b, a)
+                       span.Done()
                }
                if a.json != nil {
                        a.json.TimeDone = time.Now()
@@ -169,6 +177,7 @@ func (b *Builder) Do(ctx context.Context, root *Action) {
        for i := 0; i < par; i++ {
                wg.Add(1)
                go func() {
+                       ctx := trace.StartGoroutine(ctx)
                        defer wg.Done()
                        for {
                                select {
@@ -181,7 +190,7 @@ func (b *Builder) Do(ctx context.Context, root *Action) {
                                        b.exec.Lock()
                                        a := b.ready.pop()
                                        b.exec.Unlock()
-                                       handle(a)
+                                       handle(ctx, a)
                                case <-base.Interrupted:
                                        base.SetExitStatus(1)
                                        return