mirror of
https://github.com/gohugoio/hugo.git
synced 2024-11-21 20:46:30 -05:00
general: Fix issue causing log threads to hang indefinitely when print() panics
The function printIfNotPrinted() defined for DistinctLogger unlocked the mutex within the logger only after the print() function ran. If print panics, the mutex would stay locked and future attempts to read or write from the logger mutex would cause the goroutine to hang indefinitely. Deferred the unlocking of the mutex to prevent this. Also, put l.m[key] before the print() call since this will prevent another bug where the same warning potentially gets logged multiple times if the print() call panics. Fixes #9380
This commit is contained in:
parent
7a080b624e
commit
22055176d2
2 changed files with 58 additions and 2 deletions
|
@ -360,9 +360,10 @@ func (l *DistinctLogger) printIfNotPrinted(level, logStatement string, print fun
|
|||
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()
|
||||
l.m[key] = true
|
||||
l.Unlock()
|
||||
|
||||
}
|
||||
|
||||
// NewDistinctErrorLogger creates a new DistinctLogger that logs ERRORs
|
||||
|
|
|
@ -18,6 +18,7 @@ import (
|
|||
"reflect"
|
||||
"strings"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/gohugoio/hugo/config"
|
||||
|
||||
|
@ -58,6 +59,60 @@ 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 := 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 == false {
|
||||
loggers.PanicOnWarning = true
|
||||
defer func() {
|
||||
loggers.PanicOnWarning = 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
|
||||
|
|
Loading…
Reference in a new issue