fine grained metrics

bob/playbook/build_internal.go

@@ -55,7 +55,7 @@ func (p *Playbook) build(ctx context.Context, task *bobtask.Task) (_ processed.T
 	pt.FilterInputTook = time.Since(start)
 
 	start = time.Now()
-	rebuildRequired, rebuildCause, err := p.TaskNeedsRebuild(task.Name())
+	rebuildRequired, rebuildCause, err := p.TaskNeedsRebuild(task.TaskID, &pt)
 	errz.Fatal(err)
 	pt.NeddRebuildTook = time.Since(start)
 	boblog.Log.V(2).Info(fmt.Sprintf("TaskNeedsRebuild [rebuildRequired: %t] [cause:%s]", rebuildRequired, rebuildCause))

bob/playbook/rebuild.go

@@ -3,22 +3,19 @@ package playbook
 import (
 	"errors"
 	"fmt"
+	"time"
 
 	"github.com/benchkram/bob/bobtask"
-	"github.com/benchkram/bob/pkg/boberror"
+	"github.com/benchkram/bob/bobtask/processed"
 	"github.com/benchkram/bob/pkg/boblog"
-	"github.com/benchkram/bob/pkg/usererror"
 	"github.com/benchkram/errz"
 )
 
 // TaskNeedsRebuild check if a tasks need a rebuild by looking at its hash value
 // and its child tasks.
-func (p *Playbook) TaskNeedsRebuild(taskname string) (rebuildRequired bool, cause RebuildCause, err error) {
-	ts, ok := p.Tasks[taskname]
-	if !ok {
-		return false, "", usererror.Wrap(boberror.ErrTaskDoesNotExistF(taskname))
-	}
-	task := ts.Task
+func (p *Playbook) TaskNeedsRebuild(taskID int, pc *processed.Task) (rebuildRequired bool, cause RebuildCause, err error) {
+	task := p.TasksOptimized[taskID]
+
 	coloredName := task.ColoredName()
 
 	// Rebuild strategy set to `always`
@@ -28,27 +25,36 @@ func (p *Playbook) TaskNeedsRebuild(taskname string) (rebuildRequired bool, caus
 	}
 
 	// Did a child task change?
+	start := time.Now()
 	if p.didChildTaskChange(task.Name(), p.namePad, coloredName) {
 		boblog.Log.V(3).Info(fmt.Sprintf("%-*s\tNEEDS REBUILD\t(dependecy changed)", p.namePad, coloredName))
+		pc.NeedRebuildDidChildtaskChangeTook = time.Since(start)
 		return true, DependencyChanged, nil
 	}
+	pc.NeedRebuildDidChildtaskChangeTook = time.Since(start)
 
 	// Did the current task change?
 	// Indicating a cache miss in buildinfostore.
+	start = time.Now()
 	rebuildRequired, err = task.DidTaskChange()
 	errz.Fatal(err)
 	if rebuildRequired {
 		boblog.Log.V(3).Info(fmt.Sprintf("%-*s\tNEEDS REBUILD\t(input changed)", p.namePad, coloredName))
 		return true, InputNotFoundInBuildInfo, nil
 	}
+	pc.NeedRebuildDidTaskCHangeTook = time.Since(start)
 
 	// Check rebuild due to invalidated targets
+	start = time.Now()
 	target, err := task.Target()
+	pc.NeedRebuildTargetTook = time.Since(start)
 	if err != nil {
 		return true, "", err
 	}
 	if target != nil {
+		start = time.Now()
 		targetValid := target.VerifyShallow()
+		pc.NeedRebuildTargetVerifyShallowTook = time.Since(start)
 		if !targetValid {
 			boblog.Log.V(3).Info(fmt.Sprintf("%-*s\tNEEDS REBUILD\t(invalid targets)", p.namePad, coloredName))
 			return true, TargetInvalid, nil

bob/playbook/summary.go

@@ -36,9 +36,13 @@ func (p *Playbook) summary(processedTasks []processed.Task) {
 		boblog.Log.V(1).Info(fmt.Sprintf("  %-*s\t%s%s", p.namePad, taskName, status.Summary(), execTime))
 
 		if p.debugSummary {
-			pad := 15
+			pad := 45
 			printBuildDetails("filter-input", pad, t.FilterInputTook)
 			printBuildDetails("need-rebuild", pad, t.NeddRebuildTook)
+			printBuildDetails("need-rebuild-child-task-change?", pad, t.NeedRebuildDidChildtaskChangeTook)
+			printBuildDetails("need-rebuild-task-change?", pad, t.NeedRebuildDidTaskCHangeTook)
+			printBuildDetails("need-rebuild-target", pad, t.NeedRebuildTargetTook)
+			printBuildDetails("need-rebuild-target-verify-shallow", pad, t.NeedRebuildTargetVerifyShallowTook)
 			printBuildDetails("build", pad, t.BuildTook)
 			printBuildDetails("completion", pad, t.CompletionTook)
 		}

bobtask/processed/processed_task.go

@@ -9,8 +9,12 @@ import (
 type Task struct {
 	*bobtask.Task
 
-	FilterInputTook time.Duration
-	NeddRebuildTook time.Duration
-	BuildTook       time.Duration
-	CompletionTook  time.Duration
+	FilterInputTook                    time.Duration
+	NeddRebuildTook                    time.Duration
+	NeedRebuildDidChildtaskChangeTook  time.Duration
+	NeedRebuildDidTaskCHangeTook       time.Duration
+	NeedRebuildTargetTook              time.Duration
+	NeedRebuildTargetVerifyShallowTook time.Duration
+	BuildTook                          time.Duration
+	CompletionTook                     time.Duration
 }