From 188aba723ff71b949d4290dae3eab5ccfac2b94b Mon Sep 17 00:00:00 2001 From: Michael Mayer Date: Wed, 3 Jun 2026 08:18:05 +0000 Subject: [PATCH] Backend: Report recovered panics via SystemLog, not the DB logger #5637 --- internal/event/panic.go | 21 ++++++---- internal/event/panic_test.go | 74 ++++++++++++++++++------------------ 2 files changed, 51 insertions(+), 44 deletions(-) diff --git a/internal/event/panic.go b/internal/event/panic.go index 894d47124..e02c9ffc9 100644 --- a/internal/event/panic.go +++ b/internal/event/panic.go @@ -2,17 +2,24 @@ package event import "runtime/debug" -// LogPanic logs a recovered panic value together with the current stack trace, -// so that crashes which would otherwise terminate the process without any output -// can be diagnosed from the regular log. It does not stop the process; the caller -// decides whether to exit. +// LogPanic reports a recovered panic value together with the current stack +// trace so that crashes which would otherwise terminate the process without any +// output can be diagnosed. It does not stop the process; the caller decides +// whether to exit. +// +// It deliberately reports through SystemError (the system log) rather than the +// default Log: the default logger is persisted to the database via the event +// hub (the errors and audit_logs tables), so reporting a panic through it could +// trigger a follow-up error or panic when the database is itself the cause of +// the crash or is unavailable. The system log writes to the console only. func LogPanic(r any) { - if r == nil || Log == nil { + if r == nil { return } - Log.Errorf("panic: %v", r) - Log.Errorf("stack trace:\n%s", debug.Stack()) + // SystemError already prefixes messages with "system: ", so the wording + // avoids a leading "panic:" that would read as "system: panic:". + SystemError([]string{"panic", "%v", "%s"}, r, debug.Stack()) } // Recover recovers from a panic in the calling goroutine, if any, and logs it diff --git a/internal/event/panic_test.go b/internal/event/panic_test.go index 740dfd3ec..9f1d05140 100644 --- a/internal/event/panic_test.go +++ b/internal/event/panic_test.go @@ -8,39 +8,45 @@ import ( "github.com/stretchr/testify/assert" ) +// newTestLogger returns a logrus logger writing to buf at error level. +func newTestLogger(buf *bytes.Buffer) *logrus.Logger { + logger := logrus.New() + logger.SetOutput(buf) + logger.SetLevel(logrus.ErrorLevel) + return logger +} + func TestLogPanic(t *testing.T) { t.Run("Success", func(t *testing.T) { - var buf bytes.Buffer - logger := logrus.New() - logger.SetOutput(&buf) - logger.SetLevel(logrus.ErrorLevel) - orig := Log - Log = logger - t.Cleanup(func() { Log = orig }) + var sysBuf, logBuf bytes.Buffer + origSys, origLog := SystemLog, Log + SystemLog = newTestLogger(&sysBuf) + Log = newTestLogger(&logBuf) + t.Cleanup(func() { SystemLog = origSys; Log = origLog }) LogPanic("boom") - out := buf.String() - assert.Contains(t, out, "panic: boom") - assert.Contains(t, out, "stack trace") + out := sysBuf.String() + assert.Contains(t, out, "panic") + assert.Contains(t, out, "boom") assert.Contains(t, out, "goroutine") + // Must not be routed through the default, database-persisted logger. + assert.Empty(t, logBuf.String()) }) t.Run("Nil", func(t *testing.T) { var buf bytes.Buffer - logger := logrus.New() - logger.SetOutput(&buf) - orig := Log - Log = logger - t.Cleanup(func() { Log = orig }) + orig := SystemLog + SystemLog = newTestLogger(&buf) + t.Cleanup(func() { SystemLog = orig }) LogPanic(nil) assert.Empty(t, buf.String()) }) t.Run("NoLogger", func(t *testing.T) { - orig := Log - Log = nil - t.Cleanup(func() { Log = orig }) + orig := SystemLog + SystemLog = nil + t.Cleanup(func() { SystemLog = orig }) assert.NotPanics(t, func() { LogPanic("boom") }) }) @@ -49,12 +55,9 @@ func TestLogPanic(t *testing.T) { func TestRecover(t *testing.T) { t.Run("Panic", func(t *testing.T) { var buf bytes.Buffer - logger := logrus.New() - logger.SetOutput(&buf) - logger.SetLevel(logrus.ErrorLevel) - orig := Log - Log = logger - t.Cleanup(func() { Log = orig }) + orig := SystemLog + SystemLog = newTestLogger(&buf) + t.Cleanup(func() { SystemLog = orig }) func() { defer Recover() @@ -62,16 +65,15 @@ func TestRecover(t *testing.T) { }() out := buf.String() - assert.Contains(t, out, "panic: kaboom") + assert.Contains(t, out, "panic") + assert.Contains(t, out, "kaboom") assert.Contains(t, out, "goroutine") }) t.Run("NoPanic", func(t *testing.T) { var buf bytes.Buffer - logger := logrus.New() - logger.SetOutput(&buf) - orig := Log - Log = logger - t.Cleanup(func() { Log = orig }) + orig := SystemLog + SystemLog = newTestLogger(&buf) + t.Cleanup(func() { SystemLog = orig }) func() { defer Recover() }() @@ -82,12 +84,9 @@ func TestRecover(t *testing.T) { func TestSafe(t *testing.T) { t.Run("RecoversAndContinues", func(t *testing.T) { var buf bytes.Buffer - logger := logrus.New() - logger.SetOutput(&buf) - logger.SetLevel(logrus.ErrorLevel) - orig := Log - Log = logger - t.Cleanup(func() { Log = orig }) + orig := SystemLog + SystemLog = newTestLogger(&buf) + t.Cleanup(func() { SystemLog = orig }) ran := 0 assert.NotPanics(t, func() { @@ -96,7 +95,8 @@ func TestSafe(t *testing.T) { }) assert.Equal(t, 1, ran) - assert.Contains(t, buf.String(), "panic: boom") + assert.Contains(t, buf.String(), "panic") + assert.Contains(t, buf.String(), "boom") }) t.Run("Success", func(t *testing.T) { called := false