Improve trace logging for pulls and processes (#22633)

Our trace logging is far from perfect and is difficult to follow.

This PR:

* Add trace logging for process manager add and remove.
* Fixes an errant read file for git refs in getMergeCommit
* Brings in the pullrequest `String` and `ColorFormat` methods
introduced in #22568
* Adds a lot more logging in to testPR etc.

Ref #22578

---------

Signed-off-by: Andrew Thornton <art27@cantab.net>
Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
Co-authored-by: delvh <dev.lh@web.de>
Co-authored-by: 6543 <6543@obermui.de>
Co-authored-by: techknowlogick <techknowlogick@gitea.io>

2 files changed, 16 insertions, 8 deletions

diff --git a/modules/process/manager.go b/modules/process/manager.go
index 1272510067..fdfca3db7a 100644
--- a/modules/process/manager.go
+++ b/modules/process/manager.go
@@ -6,6 +6,7 @@ package process
 
 import (
 	"context"
+	"log"
 	"runtime/pprof"
 	"strconv"
 	"sync"
@@ -43,6 +44,18 @@ type IDType string
 // - it is simply an alias for context.CancelFunc and is only for documentary purposes
 type FinishedFunc = context.CancelFunc
 
+var Trace = defaultTrace // this global can be overridden by particular logging packages - thus avoiding import cycles
+
+func defaultTrace(start bool, pid IDType, description string, parentPID IDType, typ string) {
+	if start && parentPID != "" {
+		log.Printf("start process %s: %s (from %s) (%s)", pid, description, parentPID, typ)
+	} else if start {
+		log.Printf("start process %s: %s (%s)", pid, description, typ)
+	} else {
+		log.Printf("end process %s: %s", pid, description)
+	}
+}
+
 // Manager manages all processes and counts PIDs.
 type Manager struct {
 	mutex sync.Mutex
@@ -154,6 +167,7 @@ func (pm *Manager) Add(ctx context.Context, description string, cancel context.C
 
 	pm.processMap[pid] = process
 	pm.mutex.Unlock()
+	Trace(true, pid, description, parentPID, processType)
 
 	pprofCtx := pprof.WithLabels(ctx, pprof.Labels(DescriptionPProfLabel, description, PPIDPProfLabel, string(parentPID), PIDPProfLabel, string(pid), ProcessTypePProfLabel, processType))
 	if currentlyRunning {
@@ -185,18 +199,12 @@ func (pm *Manager) nextPID() (start time.Time, pid IDType) {
 	return start, pid
 }
 
-// Remove a process from the ProcessManager.
-func (pm *Manager) Remove(pid IDType) {
-	pm.mutex.Lock()
-	delete(pm.processMap, pid)
-	pm.mutex.Unlock()
-}
-
 func (pm *Manager) remove(process *process) {
 	pm.mutex.Lock()
 	defer pm.mutex.Unlock()
 	if p := pm.processMap[process.PID]; p == process {
 		delete(pm.processMap, process.PID)
+		Trace(false, process.PID, process.Description, process.ParentPID, process.Type)
 	}
 }
 
diff --git a/modules/process/manager_test.go b/modules/process/manager_test.go
index 527072713f..2e2e35d24a 100644
--- a/modules/process/manager_test.go
+++ b/modules/process/manager_test.go
@@ -82,7 +82,7 @@ func TestManager_Remove(t *testing.T) {
 
 	assert.NotEqual(t, GetContext(p1Ctx).GetPID(), GetContext(p2Ctx).GetPID(), "expected to get different pids got %s == %s", GetContext(p2Ctx).GetPID(), GetContext(p1Ctx).GetPID())
 
-	pm.Remove(GetPID(p2Ctx))
+	finished()
 
 	_, exists := pm.processMap[GetPID(p2Ctx)]
 	assert.False(t, exists, "PID %d is in the list but shouldn't", GetPID(p2Ctx))