improve gen stats report

Signed-off-by: Tony Worm <tony@hofstadter.io>

lib/gen/loadcue.go

@@ -55,27 +55,21 @@ func (G *Generator) LoadCue() (errs []error) {
 		errs = append(errs, err)
 	}
 
+	// Initialize Generator
+	errsI := G.Initialize()
+	if len(errsI) != 0 {
+		errs = append(errs, errsI...)
+	}
+
 	// finalize load timing stats
-	cueDecodeTime := time.Now()
-	G.Stats.CueLoadingTime = cueDecodeTime.Sub(start)
+	end := time.Now()
+	G.Stats.LoadingTime = end.Sub(start)
 
 	// Load Subgens
 	if serr := G.loadSubgens(); serr != nil {
 		errs = append(errs, serr...)
 	}
 
-	// return early if errors
-	// (we didn't do this before, and waited until after init, were there better errors this way?)
-	if errs != nil {
-		return errs
-	}
-
-	// Initialize Generator
-	errsI := G.Initialize()
-	if len(errsI) != 0 {
-		errs = append(errs, errsI...)
-	}
-
 	G.debugLoad()
 
 	return errs

lib/gen/runtime.go

@@ -39,20 +39,25 @@ type Runtime struct {
 	// Hof related
 	Generators map[string]*Generator
 	Shadow     map[string]*File
+	Stats      *RuntimeStats
 }
 
 func NewRuntime(entrypoints []string, cmdflags flags.GenFlagpole) *Runtime {
 	return &Runtime{
 		Entrypoints: entrypoints,
 		Flagpole:    cmdflags,
-
-		CueCTX: cuecontext.New(),
-
-		Generators: make(map[string]*Generator),
+		CueCTX:      cuecontext.New(),
+		Generators:  make(map[string]*Generator),
+		Stats:       new(RuntimeStats),
 	}
 }
 
 func (R *Runtime) LoadCue() []error {
+	start := time.Now()
+	defer func() {
+		end := time.Now()
+		R.Stats.CueLoadingTime = end.Sub(start)
+	}()
 
 	var errs []error
 
@@ -155,6 +160,12 @@ func (R *Runtime) ExtractGenerators() {
 }
 
 func (R *Runtime) LoadGenerators() []error {
+	start := time.Now()
+	defer func() {
+		end := time.Now()
+		R.Stats.GenLoadingTime = end.Sub(start)
+	}()
+
 	var errs []error
 
 	// Don't do in parallel yet, Cue is slow and hungry for memory @ v0.0.16
@@ -182,6 +193,12 @@ func (R *Runtime) LoadGenerators() []error {
 }
 
 func (R *Runtime) RunGenerators() []error {
+	start := time.Now()
+	defer func() {
+		end := time.Now()
+		R.Stats.GenRunningTime = end.Sub(start)
+	}()
+
 	var errs []error
 
 	// Load shadow, can this be done in parallel with the last step?
@@ -411,13 +428,25 @@ func (R *Runtime) WriteGenerator(G *Generator) (errs []error) {
 }
 
 func (R *Runtime) PrintStats() {
+	// find gens which ran
+	gens := []string{}
+	for _, G := range R.Generators {
+		if !G.Disabled {
+			gens = append(gens, G.Name)
+		}
+	}
+
+	fmt.Printf("\nHof: %s\n==========================\n", "Runtime")
+	fmt.Println("\nGens:", gens)
+	fmt.Println(R.Stats)
+
 	for _, G := range R.Generators {
 		if G.Disabled {
 			continue
 		}
 
 		G.Stats.CalcTotals(G)
-		fmt.Printf("\n%s\n==========================\n", G.Name)
+		fmt.Printf("\nGen: %s\n==========================\n", G.Name)
 		fmt.Println(G.Stats)
 	}
 }

lib/gen/stats.go

@@ -7,52 +7,59 @@ import (
 	"time"
 )
 
+type RuntimeStats struct {
+	CueLoadingTime time.Duration
+	GenLoadingTime time.Duration
+	GenRunningTime time.Duration
+}
+
 type GeneratorStats struct {
-	NumNew       int
-	NumSame      int
-	NumSkipped   int
-	NumDeleted   int
-	NumWritten   int
-	NumStatic    int
-	NumErr       int
-	TotalFiles   int
+	NumNew     int
+	NumSame    int
+	NumSkipped int
+	NumDeleted int
+	NumWritten int
+	NumStatic  int
+	NumErr     int
+	TotalFiles int
 
 	NumModified       int
 	NumModifiedRender int
 	NumModifiedOutput int
 	NumModifiedDiff3  int
 	NumConflicted     int
 
-	CueLoadingTime time.Duration
-	RenderingTime  time.Duration
-	WritingTime    time.Duration
-	TotalTime      time.Duration
+	LoadingTime   time.Duration
+	RenderingTime time.Duration
+	WritingTime   time.Duration
+	TotalTime     time.Duration
 }
 
 type FileStats struct {
 	// using 0 (false) and 1 (true) for easier summation code below
-	IsNew      int
-	IsSame     int
-	IsSkipped  int
-	IsWritten  int
-	IsErr      int
+	IsNew     int
+	IsSame    int
+	IsSkipped int
+	IsWritten int
+	IsErr     int
 
 	IsModified       int
 	IsModifiedRender int
 	IsModifiedOutput int
 	IsModifiedDiff3  int
 	IsConflicted     int
 
-	RenderingTime  time.Duration
-	CompareTime    time.Duration
-	TotalTime      time.Duration
+	RenderingTime time.Duration
+	CompareTime   time.Duration
+	TotalTime     time.Duration
 }
 
 func (S *GeneratorStats) CalcTotals(G *Generator) error {
 	// Start with own fields
 	var sum time.Time
-	sum = sum.Add(S.CueLoadingTime)
+	sum = sum.Add(S.LoadingTime)
 	sum = sum.Add(S.RenderingTime)
+	sum = sum.Add(S.WritingTime)
 
 	S.TotalTime = sum.Sub(time.Time{})
 	S.TotalFiles = len(G.Files) + S.NumStatic
@@ -75,17 +82,45 @@ func (S *GeneratorStats) CalcTotals(G *Generator) error {
 	return nil
 }
 
-func (S *GeneratorStats) String() string {
+func (S *RuntimeStats) String() string {
 	var b bytes.Buffer
 	var err error
 
 	// Parse Template
-	t := template.Must(template.New("stats").Parse(statsTemplate))
+	t := template.Must(template.New("stats").Parse(runtimeStatsTemplate))
 
 	// Round timings
 	S.CueLoadingTime = S.CueLoadingTime.Round(time.Microsecond)
-	S.RenderingTime  = S.RenderingTime.Round(time.Microsecond)
-	S.TotalTime      = S.TotalTime.Round(time.Microsecond)
+	S.GenLoadingTime = S.GenLoadingTime.Round(time.Microsecond)
+	S.GenRunningTime = S.GenRunningTime.Round(time.Microsecond)
+
+	// Render template
+	err = t.Execute(&b, S)
+	if err != nil {
+		return fmt.Sprint(err)
+	}
+
+	return b.String()
+}
+
+const runtimeStatsTemplate = `
+CueLoadingTime      {{ .CueLoadingTime }}
+GenLoadingTime      {{ .GenLoadingTime }}
+GenRunningTime      {{ .GenRunningTime }}
+`
+
+func (S *GeneratorStats) String() string {
+	var b bytes.Buffer
+	var err error
+
+	// Parse Template
+	t := template.Must(template.New("stats").Parse(genStatsTemplate))
+
+	// Round timings
+	S.LoadingTime = S.LoadingTime.Round(time.Microsecond)
+	S.RenderingTime = S.RenderingTime.Round(time.Microsecond)
+	S.WritingTime = S.WritingTime.Round(time.Microsecond)
+	S.TotalTime = S.TotalTime.Round(time.Microsecond)
 
 	// Render template
 	err = t.Execute(&b, S)
@@ -96,7 +131,7 @@ func (S *GeneratorStats) String() string {
 	return b.String()
 }
 
-const statsTemplate = `
+const genStatsTemplate = `
 NumNew              {{ .NumNew }}
 NumSame             {{ .NumSame }}
 NumSkipped          {{ .NumSkipped }}
@@ -112,7 +147,7 @@ NumModifiedOutput   {{ .NumModifiedOutput }}
 NumModifiedDiff3    {{ .NumModifiedDiff3 }}
 NumConflicted       {{ .NumConflicted }}
 
-CueLoadingTime      {{ .CueLoadingTime }}
+LoadingTime         {{ .LoadingTime }}
 RenderingTime       {{ .RenderingTime }}
 WritingTime         {{ .WritingTime }}
 TotalTime           {{ .TotalTime }}