metrics: Add simple template metrics feature
authorCameron Moore <moorereason@gmail.com>
Tue, 26 Sep 2017 18:03:04 +0000 (13:03 -0500)
committerBjørn Erik Pedersen <bjorn.erik.pedersen@gmail.com>
Tue, 26 Sep 2017 18:03:04 +0000 (20:03 +0200)
commands/hugo.go
deps/deps.go
hugolib/hugo_sites_build.go
hugolib/site.go
metrics/metrics.go [new file with mode: 0644]
tpl/template.go
tpl/tplimpl/template.go

index 388f55db970650366fd963e0244762ab0f901066..d2bf18c47862974d6331553c85107da39a57e3ec 100644 (file)
@@ -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.
index d8ba3313e4d9d37e9bcb43c68d95a5aa7c531d84..0c610c9ba658068339a01bb0608f5d5a58bf430f 100644 (file)
@@ -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
 }
 
index fa0eac702c98dc4a71dd922ad1e53f9d655552fe..f73989908ceac9994446ef0236dc62fc9b613422 100644 (file)
@@ -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.
index 39908d810bfd3f4180253aeedcaa00edd1d10637..8e1090a3143e1a942e66e5348a6438ad7e26b8bc 100644 (file)
@@ -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())
diff --git a/metrics/metrics.go b/metrics/metrics.go
new file mode 100644 (file)
index 0000000..cabf521
--- /dev/null
@@ -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://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 }
index 7be496df9b1e7cf97bcc620463fbd39063b529f9..bdb917ba9be64baceee627cefc5454b4364eba44 100644 (file)
@@ -15,6 +15,7 @@ package tpl
 
 import (
        "io"
+       "time"
 
        "text/template/parse"
 
@@ -22,6 +23,7 @@ import (
        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)
 }
 
index a8417819e3bf0c166baf225f5348f8865796bc8c..f25ff8909c863d8e2377e68f043057703e0b9f86 100644 (file)
@@ -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 {