Replace the old log setup, with structured logging etc.

Fixes #11124
This commit is contained in:
Bjørn Erik Pedersen
2023-06-16 08:17:42 +02:00
parent 0e79446586
commit 7c9fada778
80 changed files with 1273 additions and 1082 deletions

View File

@@ -24,13 +24,11 @@ import (
"path/filepath"
"sort"
"strings"
"sync"
"unicode"
"unicode/utf8"
"github.com/gohugoio/hugo/common/loggers"
"github.com/gohugoio/hugo/common/hugo"
"github.com/gohugoio/hugo/common/loggers"
"github.com/spf13/afero"
@@ -254,143 +252,6 @@ func compareStringSlices(a, b []string) bool {
return true
}
// DistinctLogger ignores duplicate log statements.
type DistinctLogger struct {
loggers.Logger
sync.RWMutex
m map[string]bool
}
func (l *DistinctLogger) Reset() {
l.Lock()
defer l.Unlock()
l.m = make(map[string]bool)
}
// Println will log the string returned from fmt.Sprintln given the arguments,
// but not if it has been logged before.
func (l *DistinctLogger) Println(v ...any) {
// fmt.Sprint doesn't add space between string arguments
logStatement := strings.TrimSpace(fmt.Sprintln(v...))
l.printIfNotPrinted("println", logStatement, func() {
l.Logger.Println(logStatement)
})
}
// Printf will log the string returned from fmt.Sprintf given the arguments,
// but not if it has been logged before.
func (l *DistinctLogger) Printf(format string, v ...any) {
logStatement := fmt.Sprintf(format, v...)
l.printIfNotPrinted("printf", logStatement, func() {
l.Logger.Printf(format, v...)
})
}
func (l *DistinctLogger) Debugf(format string, v ...any) {
logStatement := fmt.Sprintf(format, v...)
l.printIfNotPrinted("debugf", logStatement, func() {
l.Logger.Debugf(format, v...)
})
}
func (l *DistinctLogger) Debugln(v ...any) {
logStatement := fmt.Sprint(v...)
l.printIfNotPrinted("debugln", logStatement, func() {
l.Logger.Debugln(v...)
})
}
func (l *DistinctLogger) Infof(format string, v ...any) {
logStatement := fmt.Sprintf(format, v...)
l.printIfNotPrinted("info", logStatement, func() {
l.Logger.Infof(format, v...)
})
}
func (l *DistinctLogger) Infoln(v ...any) {
logStatement := fmt.Sprint(v...)
l.printIfNotPrinted("infoln", logStatement, func() {
l.Logger.Infoln(v...)
})
}
func (l *DistinctLogger) Warnf(format string, v ...any) {
logStatement := fmt.Sprintf(format, v...)
l.printIfNotPrinted("warnf", logStatement, func() {
l.Logger.Warnf(format, v...)
})
}
func (l *DistinctLogger) Warnln(v ...any) {
logStatement := fmt.Sprint(v...)
l.printIfNotPrinted("warnln", logStatement, func() {
l.Logger.Warnln(v...)
})
}
func (l *DistinctLogger) Errorf(format string, v ...any) {
logStatement := fmt.Sprint(v...)
l.printIfNotPrinted("errorf", logStatement, func() {
l.Logger.Errorf(format, v...)
})
}
func (l *DistinctLogger) Errorln(v ...any) {
logStatement := fmt.Sprint(v...)
l.printIfNotPrinted("errorln", logStatement, func() {
l.Logger.Errorln(v...)
})
}
func (l *DistinctLogger) hasPrinted(key string) bool {
l.RLock()
defer l.RUnlock()
_, found := l.m[key]
return found
}
func (l *DistinctLogger) printIfNotPrinted(level, logStatement string, print func()) {
key := level + logStatement
if l.hasPrinted(key) {
return
}
l.Lock()
defer l.Unlock()
l.m[key] = true // Placing this after print() can cause duplicate warning entries to be logged when --panicOnWarning is true.
print()
}
// NewDistinctErrorLogger creates a new DistinctLogger that logs ERRORs
func NewDistinctErrorLogger() loggers.Logger {
return &DistinctLogger{m: make(map[string]bool), Logger: loggers.NewErrorLogger()}
}
// NewDistinctLogger creates a new DistinctLogger that logs to the provided logger.
func NewDistinctLogger(logger loggers.Logger) loggers.Logger {
return &DistinctLogger{m: make(map[string]bool), Logger: logger}
}
// NewDistinctWarnLogger creates a new DistinctLogger that logs WARNs
func NewDistinctWarnLogger() loggers.Logger {
return &DistinctLogger{m: make(map[string]bool), Logger: loggers.NewWarningLogger()}
}
var (
// DistinctErrorLog can be used to avoid spamming the logs with errors.
DistinctErrorLog = NewDistinctErrorLogger()
// DistinctWarnLog can be used to avoid spamming the logs with warnings.
DistinctWarnLog = NewDistinctWarnLogger()
)
// InitLoggers resets the global distinct loggers.
func InitLoggers() {
DistinctErrorLog.Reset()
DistinctWarnLog.Reset()
}
// Deprecated informs about a deprecation, but only once for a given set of arguments' values.
// If the err flag is enabled, it logs as an ERROR (will exit with -1) and the text will
// point at the next Hugo release.
@@ -398,13 +259,9 @@ func InitLoggers() {
// plenty of time to fix their templates.
func Deprecated(item, alternative string, err bool) {
if err {
DistinctErrorLog.Errorf("%s is deprecated and will be removed in Hugo %s. %s", item, hugo.CurrentVersion.Next().ReleaseVersion(), alternative)
loggers.Log().Errorf("%s is deprecated and will be removed in Hugo %s. %s", item, hugo.CurrentVersion.Next().ReleaseVersion(), alternative)
} else {
var warnPanicMessage string
if !loggers.PanicOnWarning.Load() {
warnPanicMessage = "\n\nRe-run Hugo with the flag --panicOnWarning to get a better error message."
}
DistinctWarnLog.Warnf("%s is deprecated and will be removed in a future release. %s%s", item, alternative, warnPanicMessage)
loggers.Log().Warnf("%s is deprecated and will be removed in a future release. %s%s", item, alternative)
}
}

View File

@@ -18,9 +18,7 @@ import (
"reflect"
"strings"
"testing"
"time"
"github.com/gohugoio/hugo/common/loggers"
"github.com/gohugoio/hugo/helpers"
qt "github.com/frankban/quicktest"
@@ -55,60 +53,6 @@ func TestResolveMarkup(t *testing.T) {
}
}
func TestDistinctLoggerDoesNotLockOnWarningPanic(t *testing.T) {
// Testing to make sure logger mutex doesn't lock if warnings cause panics.
// func Warnf() of DistinctLogger is defined in general.go
l := helpers.NewDistinctLogger(loggers.NewWarningLogger())
// Set PanicOnWarning to true to reproduce issue 9380
// Ensure global variable loggers.PanicOnWarning is reset to old value after test
if !loggers.PanicOnWarning.Load() {
loggers.PanicOnWarning.Store(true)
defer func() {
loggers.PanicOnWarning.Store(false)
}()
}
// Establish timeout in case a lock occurs:
timeIsUp := make(chan bool)
timeOutSeconds := 1
go func() {
time.Sleep(time.Second * time.Duration(timeOutSeconds))
timeIsUp <- true
}()
// Attempt to run multiple logging threads in parallel
counterC := make(chan int)
goroutines := 5
for i := 0; i < goroutines; i++ {
go func() {
defer func() {
// Intentional panic successfully recovered - notify counter channel
recover()
counterC <- 1
}()
l.Warnf("Placeholder template message: %v", "In this test, logging a warning causes a panic.")
}()
}
// All goroutines should complete before timeout
var counter int
for {
select {
case <-counterC:
counter++
if counter == goroutines {
return
}
case <-timeIsUp:
t.Errorf("Unable to log warnings with --panicOnWarning within alloted time of: %v seconds. Investigate possible mutex locking on panic in distinct warning logger.", timeOutSeconds)
return
}
}
}
func TestFirstUpper(t *testing.T) {
for i, this := range []struct {
in string

View File

@@ -23,7 +23,7 @@ func newTestPathSpecFromCfgAndLang(cfg config.Provider, lang string) *helpers.Pa
}
}
fs := hugofs.NewFrom(mfs, conf.BaseConfig())
ps, err := helpers.NewPathSpec(fs, conf, loggers.NewErrorLogger())
ps, err := helpers.NewPathSpec(fs, conf, loggers.NewDefault())
if err != nil {
panic(err)
}
@@ -41,7 +41,7 @@ func newTestPathSpec(configKeyValues ...any) *helpers.PathSpec {
func newTestContentSpec(cfg config.Provider) *helpers.ContentSpec {
fs := afero.NewMemMapFs()
conf := testconfig.GetTestConfig(fs, cfg)
spec, err := helpers.NewContentSpec(conf, loggers.NewErrorLogger(), fs, nil)
spec, err := helpers.NewContentSpec(conf, loggers.NewDefault(), fs, nil)
if err != nil {
panic(err)
}