Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Do not output "Trace" level logs from process manager by default #24952

Merged
merged 2 commits into from
May 27, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion modules/log/event_writer_base.go
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ func eventWriterStartGo(ctx context.Context, w EventWriter, shared bool) {
if shared {
ctxDesc = "Logger: EventWriter (shared): " + w.GetWriterName()
}
writerCtx, writerCancel := newContext(ctx, ctxDesc)
writerCtx, writerCancel := newProcessTypedContext(ctx, ctxDesc)
go func() {
defer writerCancel()
defer close(w.Base().stopped)
Expand Down
24 changes: 8 additions & 16 deletions modules/log/init.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,16 +7,12 @@ import (
"context"
"runtime"
"strings"
"sync/atomic"

"code.gitea.io/gitea/modules/process"
"code.gitea.io/gitea/modules/util/rotatingfilewriter"
)

var (
projectPackagePrefix string
processTraceDisabled atomic.Int64
)
var projectPackagePrefix string

func init() {
_, filename, _, _ := runtime.Caller(0)
Expand All @@ -28,25 +24,21 @@ func init() {

rotatingfilewriter.ErrorPrintf = FallbackErrorf

process.Trace = func(start bool, pid process.IDType, description string, parentPID process.IDType, typ string) {
// the logger manager has its own mutex lock, so it's safe to use "Load" here
if processTraceDisabled.Load() != 0 {
return
}
process.TraceCallback = func(skip int, start bool, pid process.IDType, description string, parentPID process.IDType, typ string) {
if start && parentPID != "" {
Log(1, TRACE, "Start %s: %s (from %s) (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(parentPID, FgYellow), NewColoredValue(typ, Reset))
Log(skip+1, TRACE, "Start %s: %s (from %s) (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(parentPID, FgYellow), NewColoredValue(typ, Reset))
} else if start {
Log(1, TRACE, "Start %s: %s (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(typ, Reset))
Log(skip+1, TRACE, "Start %s: %s (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(typ, Reset))
} else {
Log(1, TRACE, "Done %s: %s", NewColoredValue(pid, FgHiYellow), NewColoredValue(description, Reset))
Log(skip+1, TRACE, "Done %s: %s", NewColoredValue(pid, FgHiYellow), NewColoredValue(description, Reset))
}
}
}

func newContext(parent context.Context, desc string) (ctx context.Context, cancel context.CancelFunc) {
func newProcessTypedContext(parent context.Context, desc string) (ctx context.Context, cancel context.CancelFunc) {
// the "process manager" also calls "log.Trace()" to output logs, so if we want to create new contexts by the manager, we need to disable the trace temporarily
processTraceDisabled.Add(1)
defer processTraceDisabled.Add(-1)
process.TraceLogDisable(true)
defer process.TraceLogDisable(false)
ctx, _, cancel = process.GetManager().AddTypedContext(parent, desc, process.SystemProcessType, false)
return ctx, cancel
}
2 changes: 1 addition & 1 deletion modules/log/logger_impl.go
Original file line number Diff line number Diff line change
Expand Up @@ -230,7 +230,7 @@ func (l *LoggerImpl) GetLevel() Level {

func NewLoggerWithWriters(ctx context.Context, name string, writer ...EventWriter) *LoggerImpl {
l := &LoggerImpl{}
l.ctx, l.ctxCancel = newContext(ctx, "Logger: "+name)
l.ctx, l.ctxCancel = newProcessTypedContext(ctx, "Logger: "+name)
l.LevelLogger = BaseLoggerToGeneralLogger(l)
l.eventWriters = map[string]EventWriter{}
l.syncLevelInternal()
Expand Down
2 changes: 1 addition & 1 deletion modules/log/manager.go
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,6 @@ func GetManager() *LoggerManager {

func NewManager() *LoggerManager {
m := &LoggerManager{writers: map[string]EventWriter{}, loggers: map[string]*LoggerImpl{}}
m.ctx, m.ctxCancel = newContext(context.Background(), "LoggerManager")
m.ctx, m.ctxCancel = newProcessTypedContext(context.Background(), "LoggerManager")
return m
}
33 changes: 25 additions & 8 deletions modules/process/manager.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,10 +6,10 @@ package process

import (
"context"
"log"
"runtime/pprof"
"strconv"
"sync"
"sync/atomic"
"time"
)

Expand Down Expand Up @@ -44,16 +44,33 @@ 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
var (
traceDisabled atomic.Int64
TraceCallback = defaultTraceCallback // this global can be overridden by particular logging packages - thus avoiding import cycles
)

// defaultTraceCallback is a no-op. Without a proper TraceCallback (provided by the logger system), this "Trace" level messages shouldn't be outputted.
func defaultTraceCallback(skip int, start bool, pid IDType, description string, parentPID IDType, typ string) {
}

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)
// TraceLogDisable disables (or revert the disabling) the trace log for the process lifecycle.
// eg: the logger system shouldn't print the trace log for themselves, that's cycle dependency (Logger -> ProcessManager -> TraceCallback -> Logger ...)
// Theoretically, such trace log should only be enabled when the logger system is ready with a proper level, so the default TraceCallback is a no-op.
func TraceLogDisable(v bool) {
if v {
traceDisabled.Add(1)
} else {
log.Printf("end process %s: %s", pid, description)
traceDisabled.Add(-1)
}
}

func Trace(start bool, pid IDType, description string, parentPID IDType, typ string) {
if traceDisabled.Load() != 0 {
// the traceDisabled counter is mainly for recursive calls, so no concurrency problem.
// because the counter can't be 0 since the caller function hasn't returned (decreased the counter) yet.
return
}
TraceCallback(1, start, pid, description, parentPID, typ)
}

// Manager manages all processes and counts PIDs.
Expand Down