metrics: Add simple template metrics feature

commands/hugo.go

@@ -241,6 +241,7 @@ func initHugoBuildCommonFlags(cmd *cobra.Command) {
  cmd.Flags().Bool("enableGitInfo", false, "add Git revision, date and author info to the pages")
 
  cmd.Flags().BoolVar(&nitro.AnalysisOn, "stepAnalysis", false, "display memory and timing of different steps of the program")
+ cmd.Flags().Bool("templateMetrics", false, "display metrics about template executions")
  cmd.Flags().Bool("pluralizeListTitles", true, "pluralize titles in lists using inflect")
  cmd.Flags().Bool("preserveTaxonomyNames", false, `preserve taxonomy names as written ("Gérard Depardieu" vs "gerard-depardieu")`)
  cmd.Flags().BoolP("forceSyncStatic", "", false, "copy all files when static is changed.")
@@ -475,6 +476,7 @@ func (c *commandeer) initializeFlags(cmd *cobra.Command) {
  "forceSyncStatic",
  "noTimes",
  "noChmod",
+ "templateMetrics",
  }
 
  // Remove these in Hugo 0.23.

deps/deps.go

@@ -8,6 +8,7 @@ import (
  "github.com/gohugoio/hugo/config"
  "github.com/gohugoio/hugo/helpers"
  "github.com/gohugoio/hugo/hugofs"
+ "github.com/gohugoio/hugo/metrics"
  "github.com/gohugoio/hugo/output"
  "github.com/gohugoio/hugo/tpl"
  jww "github.com/spf13/jwalterweatherman"
@@ -47,6 +48,8 @@ type Deps struct {
  WithTemplate func(templ tpl.TemplateHandler) error `json:"-"`
 
  translationProvider ResourceProvider
+
+ Metrics metrics.Provider
 }
 
 // ResourceProvider is used to create and refresh, and clone resources needed.
@@ -131,6 +134,10 @@ func New(cfg DepsCfg) (*Deps, error) {
  Language: cfg.Language,
  }
 
+ if cfg.Cfg.GetBool("templateMetrics") {
+ d.Metrics = metrics.NewProvider()
+ }
+
  return d, nil
 }
 

hugolib/hugo_sites_build.go

@@ -25,6 +25,10 @@ import (
 // Build builds all sites. If filesystem events are provided,
 // this is considered to be a potential partial rebuild.
 func (h *HugoSites) Build(config BuildCfg, events ...fsnotify.Event) error {
+ if h.Metrics != nil {
+ h.Metrics.Reset()
+ }
+
  t0 := time.Now()
 
  // Need a pointer as this may be modified.

hugolib/site.go

@@ -14,6 +14,7 @@
 package hugolib
 
 import (
+ "bytes"
  "errors"
  "fmt"
  "html/template"
@@ -1730,6 +1731,16 @@ func (s *Site) appendThemeTemplates(in []string) []string {
 // Stats prints Hugo builds stats to the console.
 // This is what you see after a successful hugo build.
 func (s *Site) Stats() {
+ s.Log.FEEDBACK.Println()
+
+ if s.Cfg.GetBool("templateMetrics") {
+ var b bytes.Buffer
+ s.Metrics.WriteMetrics(&b)
+
+ s.Log.FEEDBACK.Printf("Template Metrics:\n\n")
+ s.Log.FEEDBACK.Print(b.String())
+ s.Log.FEEDBACK.Println()
+ }
 
  s.Log.FEEDBACK.Printf("Built site for language %s:\n", s.Language.Lang)
  s.Log.FEEDBACK.Println(s.draftStats())

metrics/metrics.go

@@ -0,0 +1,117 @@
+// Copyright 2017 The Hugo Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+// http:https://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+// Package metrics provides simple metrics tracking features.
+package metrics
+
+import (
+ "fmt"
+ "io"
+ "sort"
+ "sync"
+ "time"
+)
+
+// The Provider interface defines an interface for measuring metrics.
+type Provider interface {
+ // MeasureSince adds a measurement for key to the metric store.
+ // Used with defer and time.Now().
+ MeasureSince(key string, start time.Time)
+
+ // WriteMetrics will write a summary of the metrics to w.
+ WriteMetrics(w io.Writer)
+
+ // Reset clears the metric store.
+ Reset()
+}
+
+// Store provides storage for a set of metrics.
+type Store struct {
+ metrics map[string][]time.Duration
+ mu *sync.Mutex
+}
+
+// NewProvider returns a new instance of a metric store.
+func NewProvider() Provider {
+ return &Store{
+ metrics: make(map[string][]time.Duration),
+ mu: &sync.Mutex{},
+ }
+}
+
+// Reset clears the metrics store.
+func (s *Store) Reset() {
+ s.mu.Lock()
+ s.metrics = make(map[string][]time.Duration)
+ s.mu.Unlock()
+}
+
+// MeasureSince adds a measurement for key to the metric store.
+func (s *Store) MeasureSince(key string, start time.Time) {
+ s.mu.Lock()
+ s.metrics[key] = append(s.metrics[key], time.Since(start))
+ s.mu.Unlock()
+}
+
+// WriteMetrics writes a summary of the metrics to w.
+func (s *Store) WriteMetrics(w io.Writer) {
+ s.mu.Lock()
+
+ results := make([]result, len(s.metrics))
+
+ var i int
+ for k, v := range s.metrics {
+ var sum time.Duration
+ var max time.Duration
+
+ for _, d := range v {
+ sum += d
+ if d > max {
+ max = d
+ }
+ }
+
+ avg := time.Duration(int(sum) / len(v))
+
+ results[i] = result{key: k, count: len(v), max: max, sum: sum, avg: avg}
+ i++
+ }
+
+ s.mu.Unlock()
+
+ // sort and print results
+ fmt.Fprintf(w, " %13s %12s %12s %5s %s\n", "cumulative", "average", "maximum", "", "")
+ fmt.Fprintf(w, " %13s %12s %12s %5s %s\n", "duration", "duration", "duration", "count", "template")
+ fmt.Fprintf(w, " %13s %12s %12s %5s %s\n", "----------", "--------", "--------", "-----", "--------")
+
+ sort.Sort(bySum(results))
+ for _, v := range results {
+ fmt.Fprintf(w, " %13s %12s %12s %5d %s\n", v.sum, v.avg, v.max, v.count, v.key)
+ }
+
+}
+
+// A result represents the calculated results for a given metric.
+type result struct {
+ key string
+ count int
+ sum time.Duration
+ max time.Duration
+ avg time.Duration
+}
+
+type bySum []result
+
+func (b bySum) Len() int { return len(b) }
+func (b bySum) Swap(i, j int) { b[i], b[j] = b[j], b[i] }
+func (b bySum) Less(i, j int) bool { return b[i].sum < b[j].sum }

tpl/template.go

@@ -15,13 +15,15 @@ package tpl
 
 import (
  "io"
+ "time"
 
  "text/template/parse"
 
  "html/template"
  texttemplate "text/template"
 
  bp "github.com/gohugoio/hugo/bufferpool"
+ "github.com/gohugoio/hugo/metrics"
 )
 
 var (
@@ -66,13 +68,16 @@ type TemplateDebugger interface {
 // TemplateAdapter implements the TemplateExecutor interface.
 type TemplateAdapter struct {
  Template
+ Metrics metrics.Provider
 }
 
 // Execute executes the current template. The actual execution is performed
 // by the embedded text or html template, but we add an implementation here so
 // we can add a timer for some metrics.
 func (t *TemplateAdapter) Execute(w io.Writer, data interface{}) error {
- // TODO(moorereason) metrics fmt.Println("Execute:", t.Name())
+ if t.Metrics != nil {
+ defer t.Metrics.MeasureSince(t.Name(), time.Now())
+ }
  return t.Template.Execute(w, data)
 }
 

tpl/tplimpl/template.go

@@ -112,15 +112,25 @@ func (t *templateHandler) Lookup(name string) *tpl.TemplateAdapter {
  // in the text template collection.
  // The templates are stored without the prefix identificator.
  name = strings.TrimPrefix(name, textTmplNamePrefix)
- return t.text.Lookup(name)
+
+ te := t.text.Lookup(name)
+ if te != nil {
+ te.Metrics = t.Deps.Metrics
+ }
+ return te
  }
 
  // Look in both
  if te := t.html.Lookup(name); te != nil {
+ te.Metrics = t.Deps.Metrics
  return te
  }
 
- return t.text.Lookup(name)
+ te := t.text.Lookup(name)
+ if te != nil {
+ te.Metrics = t.Deps.Metrics
+ }
+ return te
 }
 
 func (t *templateHandler) clone(d *deps.Deps) *templateHandler {