]> git.maquefel.me Git - brevno-suite/hugo/commitdiff
tpl/debug: Add debug.Timer
authorBjørn Erik Pedersen <bjorn.erik.pedersen@gmail.com>
Thu, 19 Oct 2023 08:53:27 +0000 (10:53 +0200)
committerBjørn Erik Pedersen <bjorn.erik.pedersen@gmail.com>
Fri, 20 Oct 2023 07:46:45 +0000 (09:46 +0200)
Closes #11580

deps/deps.go
hugolib/hugo_sites_build.go
tpl/debug/debug.go
tpl/debug/integration_test.go [new file with mode: 0644]

index 309555080a30fa85c8e6b2e077bf0ddba97eaa85..4d18120158ef0cee8c2a3a7387d8ac1b9efb6aa2 100644 (file)
@@ -33,7 +33,6 @@ import (
 // There will be normally only one instance of deps in play
 // at a given time, i.e. one per Site built.
 type Deps struct {
-
        // The logger to use.
        Log loggers.Logger `json:"-"`
 
@@ -77,6 +76,9 @@ type Deps struct {
        // BuildStartListeners will be notified before a build starts.
        BuildStartListeners *Listeners
 
+       // BuildEndListeners will be notified after a build finishes.
+       BuildEndListeners *Listeners
+
        // Resources that gets closed when the build is done or the server shuts down.
        BuildClosers *Closers
 
@@ -97,7 +99,6 @@ func (d Deps) Clone(s page.Site, conf config.AllProvider) (*Deps, error) {
        }
 
        return &d, nil
-
 }
 
 func (d *Deps) SetTempl(t *tpl.TemplateHandlers) {
@@ -132,6 +133,10 @@ func (d *Deps) Init() error {
                d.BuildStartListeners = &Listeners{}
        }
 
+       if d.BuildEndListeners == nil {
+               d.BuildEndListeners = &Listeners{}
+       }
+
        if d.BuildClosers == nil {
                d.BuildClosers = &Closers{}
        }
index 167d19eb591cb27a887786fbb621ef71c111d5dc..27fde5822ebd9ebcab4a257c1cdc75ba127f0b52 100644 (file)
@@ -17,6 +17,7 @@ import (
        "bytes"
        "context"
        "encoding/json"
+       "errors"
        "fmt"
        "path/filepath"
        "strings"
@@ -38,8 +39,6 @@ import (
 
        "github.com/gohugoio/hugo/output"
 
-       "errors"
-
        "github.com/fsnotify/fsnotify"
        "github.com/gohugoio/hugo/helpers"
 )
@@ -68,6 +67,12 @@ func (h *HugoSites) Build(config BuildCfg, events ...fsnotify.Event) error {
                defer unlock()
        }
 
+       defer func() {
+               for _, s := range h.Sites {
+                       s.Deps.BuildEndListeners.Notify()
+               }
+       }()
+
        infol := h.Log.InfoCommand("build")
 
        errCollector := h.StartErrorCollector()
@@ -344,7 +349,6 @@ func (h *HugoSites) postRenderOnce() error {
                                h.Log.Warnf("Template %s is unused, source file %s", unusedTemplate.Name(), unusedTemplate.Filename())
                        }
                }
-
        })
        return nil
 }
@@ -384,7 +388,7 @@ func (h *HugoSites) postProcess(l logg.LevelLogger) error {
                                                }
                                                // Make sure it's  written to the OS fs as this is used by
                                                // editors.
-                                               if err := afero.WriteFile(hugofs.Os, filename, b, 0666); err != nil {
+                                               if err := afero.WriteFile(hugofs.Os, filename, b, 0o666); err != nil {
                                                        h.Log.Warnf("Failed to write jsconfig.json: %s", err)
                                                }
                                        }
@@ -446,7 +450,7 @@ func (h *HugoSites) postProcess(l logg.LevelLogger) error {
                }
 
                if changed {
-                       return afero.WriteFile(h.BaseFs.PublishFs, filename, content, 0666)
+                       return afero.WriteFile(h.BaseFs.PublishFs, filename, content, 0o666)
                }
 
                return nil
@@ -512,13 +516,13 @@ func (h *HugoSites) writeBuildStats() error {
        }
 
        // Make sure it's always written to the OS fs.
-       if err := afero.WriteFile(hugofs.Os, filename, js, 0666); err != nil {
+       if err := afero.WriteFile(hugofs.Os, filename, js, 0o666); err != nil {
                return err
        }
 
        // Write to the destination as well if it's a in-memory fs.
        if !hugofs.IsOsFs(h.Fs.Source) {
-               if err := afero.WriteFile(h.Fs.WorkingDirWritable, filename, js, 0666); err != nil {
+               if err := afero.WriteFile(h.Fs.WorkingDirWritable, filename, js, 0o666); err != nil {
                        return err
                }
        }
index d07a2804e670d4cc0fa5d8ea6881052660484e26..02fe562c31728313c70528dbeb96ea3e1bc9f07d 100644 (file)
 package debug
 
 import (
+       "sort"
+       "sync"
+       "time"
+
+       "github.com/bep/logg"
        "github.com/sanity-io/litter"
        "github.com/spf13/cast"
        "github.com/yuin/goldmark/util"
@@ -24,11 +29,58 @@ import (
 
 // New returns a new instance of the debug-namespaced template functions.
 func New(d *deps.Deps) *Namespace {
-       return &Namespace{}
+       var timers map[string][]*timer
+       if d.Log.Level() <= logg.LevelInfo {
+               timers = make(map[string][]*timer)
+       }
+       ns := &Namespace{
+               timers: timers,
+       }
+
+       if ns.timers == nil {
+               return ns
+       }
+
+       l := d.Log.InfoCommand("timer")
+
+       d.BuildEndListeners.Add(func() {
+               type nameCountDuration struct {
+                       Name     string
+                       Count    int
+                       Duration time.Duration
+               }
+
+               var timersSorted []nameCountDuration
+
+               for k, v := range timers {
+                       var total time.Duration
+                       for _, t := range v {
+                               // Stop any running timers.
+                               t.Stop()
+                               total += t.elapsed
+                       }
+                       timersSorted = append(timersSorted, nameCountDuration{k, len(v), total})
+               }
+
+               sort.Slice(timersSorted, func(i, j int) bool {
+                       // Sort it so the slowest gets printed last.
+                       return timersSorted[i].Duration < timersSorted[j].Duration
+               })
+
+               for _, t := range timersSorted {
+                       l.WithField("name", t.Name).WithField("count", t.Count).WithField("duration", t.Duration).Logf("")
+               }
+
+               ns.timers = make(map[string][]*timer)
+       })
+
+       return ns
 }
 
 // Namespace provides template functions for the "debug" namespace.
 type Namespace struct {
+       timersMu sync.Mutex
+       timers   map[string][]*timer
 }
 
 // Dump returns a object dump of val as a string.
@@ -49,3 +101,44 @@ func (ns *Namespace) VisualizeSpaces(val any) string {
        s := cast.ToString(val)
        return string(util.VisualizeSpaces([]byte(s)))
 }
+
+func (ns *Namespace) Timer(name string) Timer {
+       if ns.timers == nil {
+               return nopTimer
+       }
+       ns.timersMu.Lock()
+       defer ns.timersMu.Unlock()
+       t := &timer{start: time.Now()}
+       ns.timers[name] = append(ns.timers[name], t)
+       return t
+}
+
+var nopTimer = nopTimerImpl{}
+
+type nopTimerImpl struct{}
+
+func (nopTimerImpl) Stop() string {
+       return ""
+}
+
+// Timer is a timer that can be stopped.
+type Timer interface {
+       // Stop stops the timer and returns an empty string.
+       // Stop can be called multiple times, but only the first call will stop the timer.
+       // If Stop is not called, the timer will be stopped when the build ends.
+       Stop() string
+}
+
+type timer struct {
+       start    time.Time
+       elapsed  time.Duration
+       stopOnce sync.Once
+}
+
+func (t *timer) Stop() string {
+       t.stopOnce.Do(func() {
+               t.elapsed = time.Since(t.start)
+       })
+       // This is used in templates, we need to return something.
+       return ""
+}
diff --git a/tpl/debug/integration_test.go b/tpl/debug/integration_test.go
new file mode 100644 (file)
index 0000000..6520e60
--- /dev/null
@@ -0,0 +1,45 @@
+// Copyright 2023 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 requiredF 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 debug_test
+
+import (
+       "testing"
+
+       "github.com/bep/logg"
+       "github.com/gohugoio/hugo/hugolib"
+)
+
+func TestTimer(t *testing.T) {
+       files := `
+-- hugo.toml --
+baseURL = "https://example.org/"
+disableKinds = ["taxonomy", "term"]
+-- layouts/index.html --
+{{ range seq 2 }}
+{{ $t := debug.Timer "foo" }}
+{{ seq 1 1000 }}
+{{ $t.Stop }}
+{{ end }}
+
+`
+       b := hugolib.NewIntegrationTestBuilder(
+               hugolib.IntegrationTestConfig{
+                       T:           t,
+                       TxtarString: files,
+                       LogLevel:    logg.LevelInfo,
+               },
+       ).Build()
+
+       b.AssertLogContains("imer:  name \"foo\" count '\\x02' duration")
+}