From 22055176d23417ac9039f14efdc668ed6cc6a7b9 Mon Sep 17 00:00:00 2001
From: Ephex2 <alexandrejoseph.tessier@gmail.com>
Date: Wed, 26 Jan 2022 17:44:20 -0500
Subject: 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
---
 helpers/general.go      |  5 +++--
 helpers/general_test.go | 55 +++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 58 insertions(+), 2 deletions(-)

(limited to 'helpers')

diff --git a/helpers/general.go b/helpers/general.go
index 236a763fa..472ebc4a4 100644
--- a/helpers/general.go
+++ b/helpers/general.go
@@ -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
diff --git a/helpers/general_test.go b/helpers/general_test.go
index 7fe00c51a..be9834d3f 100644
--- a/helpers/general_test.go
+++ b/helpers/general_test.go
@@ -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
-- 
cgit v1.2.3