commit 0927cf739fee9646c7fb917965799d9acf080922
parent 26a5e89faa6dd1d40d6e731ab10e565b5323dfd3
Author: Bjørn Erik Pedersen <bjorn.erik.pedersen@gmail.com>
Date: Wed, 16 Feb 2022 10:26:42 +0100
tpl/partials: Make sure a cached partial is invoked only once
This commit revises the locking strategy for `partialCached`. We have added a benchmark that may be a little artificial, but it should at least show that we're not losing any performance over this:
```bash
name old time/op new time/op delta
IncludeCached-10 12.2ms ± 2% 11.3ms ± 1% -7.36% (p=0.029 n=4+4)
name old alloc/op new alloc/op delta
IncludeCached-10 7.17MB ± 0% 5.09MB ± 0% -29.00% (p=0.029 n=4+4)
name old allocs/op new allocs/op delta
IncludeCached-10 128k ± 1% 70k ± 0% -45.42% (p=0.029 n=4+4)
```
This commit also revises the template metrics hints logic a little, and add a test for it, which output is currently this:
```bash
cumulative average maximum cache percent cached total
duration duration duration potential cached count count template
---------- -------- -------- --------- ------- ------ ----- --------
163.334µs 163.334µs 163.334µs 0 0 0 1 index.html
23.749µs 5.937µs 19.916µs 25 50 2 4 partials/dynamic1.html
9.625µs 4.812µs 6.75µs 100 50 1 2 partials/static1.html
7.625µs 7.625µs 7.625µs 100 0 0 1 partials/static2.html
```
Some notes:
* The duration now includes the cached invocations (which should be very short)
* A cached template gets executed once before it gets cached, so the "percent cached" will never be 100.
Fixes #4086
Fixes #9506
Diffstat:
6 files changed, 171 insertions(+), 14 deletions(-)
diff --git a/htesting/hqt/checkers.go b/htesting/hqt/checkers.go
@@ -63,7 +63,7 @@ type stringChecker struct {
argNames
}
-// Check implements Checker.Check by checking that got and args[0] represents the same normalized text (whitespace etc. trimmed).
+// Check implements Checker.Check by checking that got and args[0] represents the same normalized text (whitespace etc. removed).
func (c *stringChecker) Check(got interface{}, args []interface{}, note func(key string, value interface{})) (err error) {
s1, s2 := cast.ToString(got), cast.ToString(args[0])
@@ -81,11 +81,12 @@ func (c *stringChecker) Check(got interface{}, args []interface{}, note func(key
}
func normalizeString(s string) string {
+ s = strings.ReplaceAll(s, "\r\n", "\n")
+
lines := strings.Split(strings.TrimSpace(s), "\n")
for i, line := range lines {
- lines[i] = strings.TrimSpace(line)
+ lines[i] = strings.Join(strings.Fields(strings.TrimSpace(line)), "")
}
-
return strings.Join(lines, "\n")
}
diff --git a/tpl/math/math.go b/tpl/math/math.go
@@ -17,6 +17,7 @@ package math
import (
"errors"
"math"
+ "sync/atomic"
_math "github.com/gohugoio/hugo/common/math"
@@ -162,3 +163,14 @@ func (ns *Namespace) Sqrt(a interface{}) (float64, error) {
func (ns *Namespace) Sub(a, b interface{}) (interface{}, error) {
return _math.DoArithmetic(a, b, '-')
}
+
+var counter uint64
+
+// Counter increments and returns a global counter.
+// This was originally added to be used in tests where now.UnixNano did not
+// have the needed precision (especially on Windows).
+// Note that given the parallel nature of Hugo, you cannot use this to get sequences of numbers,
+// and the counter will reset on new builds.
+func (ns *Namespace) Counter() uint64 {
+ return atomic.AddUint64(&counter, uint64(1))
+}
diff --git a/tpl/partials/init.go b/tpl/partials/init.go
@@ -18,14 +18,14 @@ import (
"github.com/gohugoio/hugo/tpl/internal"
)
-const name = "partials"
+const namespaceName = "partials"
func init() {
f := func(d *deps.Deps) *internal.TemplateFuncsNamespace {
ctx := New(d)
ns := &internal.TemplateFuncsNamespace{
- Name: name,
+ Name: namespaceName,
Context: func(args ...interface{}) (interface{}, error) { return ctx, nil },
}
diff --git a/tpl/partials/init_test.go b/tpl/partials/init_test.go
@@ -33,7 +33,7 @@ func TestInit(t *testing.T) {
BuildStartListeners: &deps.Listeners{},
Log: loggers.NewErrorLogger(),
})
- if ns.Name == name {
+ if ns.Name == namespaceName {
found = true
break
}
diff --git a/tpl/partials/integration_test.go b/tpl/partials/integration_test.go
@@ -14,8 +14,14 @@
package partials_test
import (
+ "bytes"
+ "fmt"
+ "regexp"
+ "sort"
+ "strings"
"testing"
+ "github.com/gohugoio/hugo/htesting/hqt"
"github.com/gohugoio/hugo/hugolib"
)
@@ -68,3 +74,128 @@ partialCached: foo
partialCached: foo
`)
}
+
+func TestIncludeCacheHints(t *testing.T) {
+ t.Parallel()
+
+ files := `
+-- config.toml --
+baseURL = 'http://example.com/'
+templateMetrics=true
+templateMetricsHints=true
+disableKinds = ["page", "section", "taxonomy", "term", "sitemap"]
+[outputs]
+home = ["HTML"]
+-- layouts/index.html --
+{{ partials.IncludeCached "static1.html" . }}
+{{ partials.IncludeCached "static1.html" . }}
+{{ partials.Include "static2.html" . }}
+
+D1I: {{ partials.Include "dynamic1.html" . }}
+D1C: {{ partials.IncludeCached "dynamic1.html" . }}
+D1C: {{ partials.IncludeCached "dynamic1.html" . }}
+D1C: {{ partials.IncludeCached "dynamic1.html" . }}
+H1I: {{ partials.Include "halfdynamic1.html" . }}
+H1C: {{ partials.IncludeCached "halfdynamic1.html" . }}
+H1C: {{ partials.IncludeCached "halfdynamic1.html" . }}
+
+-- layouts/partials/static1.html --
+P1
+-- layouts/partials/static2.html --
+P2
+-- layouts/partials/dynamic1.html --
+{{ math.Counter }}
+-- layouts/partials/halfdynamic1.html --
+D1
+{{ math.Counter }}
+
+
+ `
+
+ b := hugolib.NewIntegrationTestBuilder(
+ hugolib.IntegrationTestConfig{
+ T: t,
+ TxtarString: files,
+ },
+ ).Build()
+
+ // fmt.Println(b.FileContent("public/index.html"))
+
+ var buf bytes.Buffer
+ b.H.Metrics.WriteMetrics(&buf)
+
+ got := buf.String()
+
+ // Get rid of all the durations, they are never the same.
+ durationRe := regexp.MustCompile(`\b[\.\d]*(ms|µs|s)\b`)
+
+ normalize := func(s string) string {
+ s = durationRe.ReplaceAllString(s, "")
+ linesIn := strings.Split(s, "\n")[3:]
+ var lines []string
+ for _, l := range linesIn {
+ l = strings.TrimSpace(l)
+ if l == "" {
+ continue
+ }
+ lines = append(lines, l)
+ }
+
+ sort.Strings(lines)
+
+ return strings.Join(lines, "\n")
+ }
+
+ got = normalize(got)
+
+ expect := `
+ 0 0 0 1 index.html
+ 100 0 0 1 partials/static2.html
+ 100 50 1 2 partials/static1.html
+ 25 50 2 4 partials/dynamic1.html
+ 66 33 1 3 partials/halfdynamic1.html
+ `
+
+ b.Assert(got, hqt.IsSameString, expect)
+}
+
+// gobench --package ./tpl/partials
+func BenchmarkIncludeCached(b *testing.B) {
+ files := `
+-- config.toml --
+baseURL = 'http://example.com/'
+-- layouts/index.html --
+-- layouts/_default/single.html --
+{{ partialCached "heavy.html" "foo" }}
+-- layouts/partials/heavy.html --
+{{ $result := slice }}
+{{ range site.RegularPages }}
+{{ $result = $result | append (dict "title" .Title "link" .RelPermalink "readingTime" .ReadingTime) }}
+{{ end }}
+{{ range $result }}
+* {{ .title }} {{ .link }} {{ .readingTime }}
+{{ end }}
+
+
+`
+
+ for i := 1; i < 100; i++ {
+ files += fmt.Sprintf("\n-- content/p%d.md --\n---\ntitle: page\n---\n"+strings.Repeat("FOO ", i), i)
+ }
+
+ cfg := hugolib.IntegrationTestConfig{
+ T: b,
+ TxtarString: files,
+ }
+ builders := make([]*hugolib.IntegrationTestBuilder, b.N)
+
+ for i, _ := range builders {
+ builders[i] = hugolib.NewIntegrationTestBuilder(cfg)
+ }
+
+ b.ResetTimer()
+
+ for i := 0; i < b.N; i++ {
+ builders[i].Build()
+ }
+}
diff --git a/tpl/partials/partials.go b/tpl/partials/partials.go
@@ -24,6 +24,7 @@ import (
"reflect"
"strings"
"sync"
+ "time"
texttemplate "github.com/gohugoio/hugo/tpl/internal/go_templates/texttemplate"
@@ -44,6 +45,13 @@ type partialCacheKey struct {
variant interface{}
}
+func (k partialCacheKey) templateName() string {
+ if !strings.HasPrefix(k.name, "partials/") {
+ return "partials/" + k.name
+ }
+ return k.name
+}
+
// partialCache represents a cache of partials protected by a mutex.
type partialCache struct {
sync.RWMutex
@@ -211,6 +219,7 @@ func createKey(name string, variants ...interface{}) (partialCacheKey, error) {
var errUnHashable = errors.New("unhashable")
func (ns *Namespace) getOrCreate(key partialCacheKey, context interface{}) (result interface{}, err error) {
+ start := time.Now()
defer func() {
if r := recover(); r != nil {
err = r.(error)
@@ -226,9 +235,20 @@ func (ns *Namespace) getOrCreate(key partialCacheKey, context interface{}) (resu
ns.cachedPartials.RUnlock()
if ok {
+ if ns.deps.Metrics != nil {
+ ns.deps.Metrics.TrackValue(key.templateName(), p, true)
+ // The templates that gets executed is measued in Execute.
+ // We need to track the time spent in the cache to
+ // get the totals correct.
+ ns.deps.Metrics.MeasureSince(key.templateName(), start)
+
+ }
return p, nil
}
+ ns.cachedPartials.Lock()
+ defer ns.cachedPartials.Unlock()
+
var name string
name, p, err = ns.include(key.name, context)
if err != nil {
@@ -236,14 +256,7 @@ func (ns *Namespace) getOrCreate(key partialCacheKey, context interface{}) (resu
}
if ns.deps.Metrics != nil {
- ns.deps.Metrics.TrackValue(name, p, true)
- }
-
- ns.cachedPartials.Lock()
- defer ns.cachedPartials.Unlock()
- // Double-check.
- if p2, ok := ns.cachedPartials.p[key]; ok {
- return p2, nil
+ ns.deps.Metrics.TrackValue(name, p, false)
}
ns.cachedPartials.p[key] = p