Skip to content

logger: fix HandlePanic to actually recover deferred panics - #158

Open
neddp wants to merge 2 commits into
developfrom
fix-handlepanic-recover
Open

neddp wants to merge 2 commits into
developfrom
fix-handlepanic-recover

Conversation

@neddp

@neddp neddp commented Oct 14, 2026

Copy link
Copy Markdown
Member

Summary

logger.HandlePanic does not recover panics when used as documented (defer logger.HandlePanic(tag)). The panic escapes unhandled: the intended Panic: ... log line and os.Exit(2) never run, and the process instead dies with a raw Go runtime trace. asyncLogger.HandlePanic has the same problem (and its FlushTimeout before exit never runs either).

Root cause

Go only honours recover() when it is called directly by the function that was deferred — not by any function that deferred function calls. The current code delegates recover() to a shared helper:

func (l *logger) recoverPanic(tag string) (didPanic bool) {
	if e := recover(); e != nil { // recover() lives here
		...
		return true
	}
	return false
}

func (l *logger) HandlePanic(tag string) { // <- the deferred frame
	if l.recoverPanic(tag) {               // recover() runs one frame too deep
		os.Exit(2)
	}
}

With defer logger.HandlePanic(tag), the deferred frame is HandlePanic, but recover() is called from recoverPanic. The runtime's recover check requires the caller of recover() to be the deferred frame, so it returns nil, recoverPanic returns false, os.Exit(2) is skipped, and the panic propagates.

Fix

Call recover() directly inside each deferred function and keep only the formatting in a helper that receives the already-recovered value:

func (l *logger) HandlePanic(tag string) {
	if e := recover(); e != nil {
		l.logPanic(tag, e)
		osExit(2)
	}
}

asyncLogger.HandlePanic is fixed the same way and still flushes before exit. An osExit seam (defaulting to os.Exit) lets the new tests assert the exit behaviour without terminating the test process.

Tests

Added internal tests (logger/handle_panic_internal_test.go) covering both the sync and async loggers: a deferred HandlePanic must recover the panic, log Panic: ..., and call os.Exit(2). The tests fail against the previous delegated implementation and pass with this change. Existing suite passes under -race.

History / impact

The regression dates to the async logger refactor (commit f8bb60f0, 2016), which extracted the recover logic into the shared helper. It went unnoticed because every caller uses HandlePanic to log-and-exit at a top-level defer: both the fixed and broken paths exit with status 2 and print a panic trace to stderr, so the only observable difference was the log format (and the loss of structured logging / async flush on panic).

HandlePanic delegated recover() to an inner helper (recoverPanic). Go only
honours recover() when it is called directly by the function that was
deferred, not by any function that function calls. Because callers use
"defer logger.HandlePanic(tag)", recover() ran one frame too deep, always
returned nil, and the panic escaped unhandled -- so the structured
"Panic: ..." log and os.Exit(2) never ran and the process crashed with a
raw runtime trace instead.

Call recover() directly inside both logger.HandlePanic and
asyncLogger.HandlePanic, and move only the formatting into a logPanic
helper that takes the already-recovered value. Add an osExit seam and
internal tests covering both loggers; the tests fail against the previous
delegated implementation.

This regression dates back to the async logger refactor (f8bb60f, 2016).
@coderabbitai

coderabbitai Bot commented Oct 14, 2026 •

Copy link
Copy Markdown

Review in Change Stack →

No actionable comments were generated in the recent review. 🎉

ℹ️ Recent review info
⚙️ Run configuration
  • Configuration used: Organization UI
  • Review profile: ASSERTIVE
  • Plan: Advanced
  • Run ID: 237c6115-a50f-42b0-b414-b8e63bcf9763
📥 Commits

Reviewing files that changed from the base of the PR and between 1561254 and e73a51f.

📒 Files selected for processing: 5
  • logger/async.go
  • logger/handle_panic_fixture/main.go
  • logger/handle_panic_test.go
  • logger/logger.go
  • logger/logger_suite_test.go

Included review availability: This review used your included allowance. Your plan provides up to 1 included review per hour; 0 remain after this review.

Walkthrough

HandlePanic now calls recover() directly and logs recovered values through logPanic, which formats the value and includes a stack trace. The asynchronous logger retains its 30-second flush and exit-status-2 behavior. A fixture and subprocess tests cover panic and no-panic execution with synchronous and asynchronous logging.

Priority: ⬇️ Low

Merge Risk: ⚪ Minimal · up to e73a5

The panic-handling change is mergeable after normal checks; no actionable issue remains in the supplied review evidence.

Pre-merge checks: Passed 4 · Failed 1

Failed Failed checks: 1 warning

Check name Status Explanation Resolution
Docstring Coverage Warning Docstring coverage is 0.00% which is insufficient. The required threshold is 80.00%. Docstring coverage is scoped to functions touched by this diff. Analyzed 2 functions across 6 files. Write docstrings for the functions missing them to satisfy the coverage threshold.
Passed Passed checks: 4 passed
Check name Status Explanation
Title check Passed The title clearly and concisely describes the main change: fixing HandlePanic so deferred panics recover correctly.
Description check Passed The description is directly related to the changes. It explains the recovery bug, the implementation fix, and the integration tests for synchronous and asynchronous loggers.
Linked Issues check Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check Passed Check skipped because no linked issues were found for this pull request.
  • Fix all pre-merge checks with AI
✨ Finishing Touches: 💡 1
📝 Generate docstrings: 💡
  • Commit to this branch
  • Create a new PR
🧪 Generate unit tests (beta)
  • Commit to this branch
  • Create a new PR
  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The implementation correctly addresses Go’s direct-recovery requirement and includes focused regression coverage.

0 open findings

What changed in this PR

Fixes panic recovery for synchronous and asynchronous loggers by calling recover() directly in deferred handlers.

Changes:

  • Extracts panic formatting into logPanic.
  • Adds a testable osExit seam.
  • Adds coverage for recovery, logging, async flushing, and exit behavior.
File Description
logger/​logger.go Corrects synchronous panic recovery and exit handling.
logger/​async.go Corrects async recovery while preserving flush-before-exit.
logger/​handle_panic_internal_test.go Tests panic and non-panic behavior for both logger types.

🧠 Review effort: Balanced


💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread logger/async.go Outdated
l.log.logPanic(tag, e)
l.FlushTimeout(time.Second * 30) //nolint:errcheck
os.Exit(2)
osExit(2)

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seam is a bit weird - I think we could use some gexec to make it better so that we don't have to insert it into production code. We could either compile a small fixture that panics and check the exit code like in #148, or use gexec to launch a sub-process in which we check the exit code.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @selzoc,

Thanks for the review!

I was unsure how to handle this correctly. I followed the approach in the referenced PR and I think it looks better now.

@github-project-automation github-project-automation Bot moved this from Pending Merge | Prioritized to Waiting for Changes | Open for Contribution in Foundational Infrastructure Working Group Oct 14, 2026
Replace the package-level osExit seam with a real subprocess test:
HandlePanic now calls os.Exit(2) directly, and a small fixture
binary (handle_panic_fixture) is compiled and run via gexec to
assert the real exit code and panic log on stderr, for both the
sync and async loggers. This matches the existing gexec pattern in
the main/ suite and keeps test-only scaffolding out of production
code.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The focused recovery fix and regression tests have no identified blocking issues; tests were not executed during this review.

No open issues 🎉

Review effort: Balanced

@neddp
neddp requested a review from selzoc October 20, 2026 05:18
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

Status: Waiting for Changes | Open for Contribution

Development

Successfully merging this pull request may close these issues.

3 participants