metrics: Add cached count tracking

Track cached partial executions and display more useful info when showing the hints output. Also group cache hints and counters together to the right of the timing measurements. Sample output: cumulative average maximum cache percent cached total duration duration duration potential cached count count template ---------- -------- -------- --------- ------- ------ ----- -------- 2.6973ms 674.325µs 857.3µs 0 0 0 4 _internal/_default/rss.xml 2.6295ms 657.375µs 861.3µs 0 0 0 4 _default/single.html 1.2563ms 314.075µs 381.5µs 0 0 0 4 news/single.html 799.2µs 399.6µs 573.3µs 0 0 0 2 _internal/_default/sitemap.xml 667.3µs 66.73µs 238.6µs 84 0 0 10 partials/header.html 656.7µs 328.35µs 459.4µs 0 0 0 2 _default/list.html 479.7µs 47.97µs 158µs 92 0 0 10 partials/head.html 323.3µs 323.3µs 323.3µs 0 0 0 1 _internal/alias.html 200.7µs 200.7µs 200.7µs 0 0 0 1 _internal/_default/sitemapindex.xml 36.1µs 6.016µs 32.6µs 100 33 2 6 partials/footer.html 27.4µs 13.7µs 26.7µs 0 0 0 2 index.html Fixes gohugoio#8375
bep · Feb 16, 2022 · d162283 · d162283
1 parent ea6bcd6
commit d162283
Show file tree

Hide file tree

Showing 3 changed files with 125 additions and 30 deletions.
diff --git a/metrics/metrics.go b/metrics/metrics.go
@@ -25,11 +25,9 @@ import (
 	"sync"
 	"time"
 
-	"github.com/gohugoio/hugo/helpers"
-
 	"github.com/gohugoio/hugo/common/types"
-
 	"github.com/gohugoio/hugo/compare"
+	"github.com/gohugoio/hugo/helpers"
 )
 
 // The Provider interface defines an interface for measuring metrics.
@@ -42,7 +40,7 @@ type Provider interface {
 	WriteMetrics(w io.Writer)
 
 	// TrackValue tracks the value for diff calculations etc.
-	TrackValue(key string, value interface{})
+	TrackValue(key string, value interface{}, cached bool)
 
 	// Reset clears the metric store.
 	Reset()
@@ -54,8 +52,6 @@ type diff struct {
 	simSum   int
 }
 
-var counter = 0
-
 func (d *diff) add(v interface{}) *diff {
 	if types.IsNil(d.baseline) {
 		d.baseline = v
@@ -77,6 +73,8 @@ type Store struct {
 	mu             sync.Mutex
 	diffs          map[string]*diff
 	diffmu         sync.Mutex
+	cached         map[string]int
+	cachedmu       sync.Mutex
 }
 
 // NewProvider returns a new instance of a metric store.
@@ -85,6 +83,7 @@ func NewProvider(calculateHints bool) Provider {
 		calculateHints: calculateHints,
 		metrics:        make(map[string][]time.Duration),
 		diffs:          make(map[string]*diff),
+		cached:         make(map[string]int),
 	}
 }
 
@@ -93,33 +92,38 @@ func (s *Store) Reset() {
 	s.mu.Lock()
 	s.metrics = make(map[string][]time.Duration)
 	s.mu.Unlock()
+
 	s.diffmu.Lock()
 	s.diffs = make(map[string]*diff)
 	s.diffmu.Unlock()
+
+	s.cachedmu.Lock()
+	s.cached = make(map[string]int)
+	s.cachedmu.Unlock()
 }
 
 // TrackValue tracks the value for diff calculations etc.
-func (s *Store) TrackValue(key string, value interface{}) {
+func (s *Store) TrackValue(key string, value interface{}, cached bool) {
 	if !s.calculateHints {
 		return
 	}
 
 	s.diffmu.Lock()
-	var (
-		d     *diff
-		found bool
-	)
-
-	d, found = s.diffs[key]
+	d, found := s.diffs[key]
 
 	if !found {
 		d = &diff{}
 		s.diffs[key] = d
 	}
 
 	d.add(value)
-
 	s.diffmu.Unlock()
+
+	if cached {
+		s.cachedmu.Lock()
+		s.cached[key] = s.cached[key] + 1
+		s.cachedmu.Unlock()
+	}
 }
 
 // MeasureSince adds a measurement for key to the metric store.
@@ -155,17 +159,18 @@ func (s *Store) WriteMetrics(w io.Writer) {
 		}
 
 		avg := time.Duration(int(sum) / len(v))
+		cacheCount := s.cached[k]
 
-		results[i] = result{key: k, count: len(v), max: max, sum: sum, avg: avg, cacheFactor: cacheFactor}
+		results[i] = result{key: k, count: len(v), max: max, sum: sum, avg: avg, cacheCount: cacheCount, cacheFactor: cacheFactor}
 		i++
 	}
 
 	s.mu.Unlock()
 
 	if s.calculateHints {
-		fmt.Fprintf(w, "  %9s  %13s  %12s  %12s  %5s  %s\n", "cache", "cumulative", "average", "maximum", "", "")
-		fmt.Fprintf(w, "  %9s  %13s  %12s  %12s  %5s  %s\n", "potential", "duration", "duration", "duration", "count", "template")
-		fmt.Fprintf(w, "  %9s  %13s  %12s  %12s  %5s  %s\n", "-----", "----------", "--------", "--------", "-----", "--------")
+		fmt.Fprintf(w, "  %13s  %12s  %12s  %9s  %7s  %6s  %5s  %s\n", "cumulative", "average", "maximum", "cache", "percent", "cached", "total", "")
+		fmt.Fprintf(w, "  %13s  %12s  %12s  %9s  %7s  %6s  %5s  %s\n", "duration", "duration", "duration", "potential", "cached", "count", "count", "template")
+		fmt.Fprintf(w, "  %13s  %12s  %12s  %9s  %7s  %6s  %5s  %s\n", "----------", "--------", "--------", "---------", "-------", "------", "-----", "--------")
 	} else {
 		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")
@@ -176,7 +181,7 @@ func (s *Store) WriteMetrics(w io.Writer) {
 	sort.Sort(bySum(results))
 	for _, v := range results {
 		if s.calculateHints {
-			fmt.Fprintf(w, "  %9d %13s  %12s  %12s  %5d  %s\n", v.cacheFactor, v.sum, v.avg, v.max, v.count, v.key)
+			fmt.Fprintf(w, "  %13s  %12s  %12s  %9d  %7.f  %6d  %5d  %s\n", v.sum, v.avg, v.max, v.cacheFactor, float64(v.cacheCount)/float64(v.count)*100, v.cacheCount, v.count, v.key)
 		} else {
 			fmt.Fprintf(w, "  %13s  %12s  %12s  %5d  %s\n", v.sum, v.avg, v.max, v.count, v.key)
 		}
@@ -187,6 +192,7 @@ func (s *Store) WriteMetrics(w io.Writer) {
 type result struct {
 	key         string
 	count       int
+	cacheCount  int
 	cacheFactor int
 	sum         time.Duration
 	max         time.Duration

diff --git a/tpl/partials/integration_test.go b/tpl/partials/integration_test.go
@@ -0,0 +1,70 @@
+// Copyright 2022 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 partials_test
+
+import (
+	"testing"
+
+	"github.com/gohugoio/hugo/hugolib"
+)
+
+func TestInclude(t *testing.T) {
+	t.Parallel()
+
+	files := `
+-- config.toml --
+baseURL = 'http://example.com/'
+-- layouts/index.html --
+partial: {{ partials.Include "foo.html" . }}
+-- layouts/partials/foo.html --
+foo
+  `
+
+	b := hugolib.NewIntegrationTestBuilder(
+		hugolib.IntegrationTestConfig{
+			T:           t,
+			TxtarString: files,
+		},
+	).Build()
+
+	b.AssertFileContent("public/index.html", `
+partial: foo
+`)
+}
+
+func TestIncludeCached(t *testing.T) {
+	t.Parallel()
+
+	files := `
+-- config.toml --
+baseURL = 'http://example.com/'
+-- layouts/index.html --
+partialCached: {{ partials.IncludeCached "foo.html" . }}
+partialCached: {{ partials.IncludeCached "foo.html" . }}
+-- layouts/partials/foo.html --
+foo
+  `
+
+	b := hugolib.NewIntegrationTestBuilder(
+		hugolib.IntegrationTestConfig{
+			T:           t,
+			TxtarString: files,
+		},
+	).Build()
+
+	b.AssertFileContent("public/index.html", `
+partialCached: foo
+partialCached: foo
+`)
+}
diff --git a/tpl/partials/partials.go b/tpl/partials/partials.go
@@ -93,23 +93,41 @@ func (c *contextWrapper) Set(in interface{}) string {
 // Else, the rendered output will be returned:
 // A string if the partial is a text/template, or template.HTML when html/template.
 func (ns *Namespace) Include(name string, contextList ...interface{}) (interface{}, error) {
-	name = strings.TrimPrefix(name, "partials/")
+	name, result, err := ns.include(name, contextList...)
+	if err != nil {
+		return result, err
+	}
+
+	if ns.deps.Metrics != nil {
+		ns.deps.Metrics.TrackValue(name, result, false)
+	}
 
+	return result, nil
+}
+
+// include is a helper function that lookups and executes the named partial.
+// Returns the final template name and the rendered output.
+func (ns *Namespace) include(name string, contextList ...interface{}) (string, interface{}, error) {
 	var context interface{}
 	if len(contextList) > 0 {
 		context = contextList[0]
 	}
 
-	n := "partials/" + name
-	templ, found := ns.deps.Tmpl().Lookup(n)
+	var n string
+	if strings.HasPrefix(name, "partials/") {
+		n = name
+	} else {
+		n = "partials/" + name
+	}
 
+	templ, found := ns.deps.Tmpl().Lookup(n)
 	if !found {
 		// For legacy reasons.
 		templ, found = ns.deps.Tmpl().Lookup(n + ".html")
 	}
 
 	if !found {
-		return "", fmt.Errorf("partial %q not found", name)
+		return "", "", fmt.Errorf("partial %q not found", name)
 	}
 
 	var info tpl.ParseInfo
@@ -136,7 +154,7 @@ func (ns *Namespace) Include(name string, contextList ...interface{}) (interface
 	}
 
 	if err := ns.deps.Tmpl().Execute(templ, w, context); err != nil {
-		return "", err
+		return "", "", err
 	}
 
 	var result interface{}
@@ -149,11 +167,7 @@ func (ns *Namespace) Include(name string, contextList ...interface{}) (interface
 		result = template.HTML(w.(fmt.Stringer).String())
 	}
 
-	if ns.deps.Metrics != nil {
-		ns.deps.Metrics.TrackValue(templ.Name(), result)
-	}
-
-	return result, nil
+	return templ.Name(), result, nil
 }
 
 // IncludeCached executes and caches partial templates.  The cache is created with name+variants as the key.
@@ -215,11 +229,16 @@ func (ns *Namespace) getOrCreate(key partialCacheKey, context interface{}) (resu
 		return p, nil
 	}
 
-	p, err = ns.Include(key.name, context)
+	var name string
+	name, p, err = ns.include(key.name, context)
 	if err != nil {
 		return nil, err
 	}
 
+	if ns.deps.Metrics != nil {
+		ns.deps.Metrics.TrackValue(name, p, true)
+	}
+
 	ns.cachedPartials.Lock()
 	defer ns.cachedPartials.Unlock()
 	// Double-check.