Skip to content

fix(websocket): stop LogCallbackEvent broadcast recursion in shutdown - #101

Merged
AdaInTheLab merged 1 commit into
mainfrom
fix/log-callback-reentrancy
Jun 3, 2026
Merged

AdaInTheLab merged 1 commit into
mainfrom
fix/log-callback-reentrancy

Conversation

@AdaInTheLab

Copy link
Copy Markdown
Collaborator

Summary

EventBroadcaster.Initialize subscribed to LogCallbackEvent with e => Broadcast("LogCallback", e). Broadcast's catch block called Log.Warning(...) on failure. On 7DTD, Log.Warning fires another LogCallbackEvent through the same bus → re-enters this subscriber → Broadcast throws again → Log.Warning again → infinite recursion → stack overflow → KC crashes.

The throw is reliably reproducible during shutdown: once the WebSocketServer manager has stopped, _server.WebSocketServices...Broadcast(json) raises "The current state of the manager is not Start." Observed live on a Windows prod box — 65+ minutes after a botched auto-start, KC's GracefulRestart wedge cascade ended in "Error in event handler for LogCallbackEvent: The requested operation caused a stack overflow." repeated dozens of times in the log, crashing KC and forcing a service auto-restart.

Fix, scoped narrowly to the LogCallbackEvent path

  1. [ThreadStatic] _inLogBroadcast re-entrancy guard. Only on the LogCallback path — other event types don't loop back into the logger from their failure handler, so they keep the existing Log.Warning-on-failure to surface real broadcast bugs.

  2. Pulled the LogCallbackEvent subscriber out into a named BroadcastLogCallback method so the guard logic stays readable instead of being inlined in a lambda. Sets the flag, calls Broadcast, clears the flag in finally.

  3. Broadcast<T> gains a suppressFailureLogging parameter. When true (LogCallbackEvent path), the catch falls back to Console.Error.WriteLine instead of Log.Warning so the failure notification itself cannot fire a fresh LogCallbackEvent and restart the recursion. Wrapped in its own try/catch in case stderr is also unhappy during shutdown.

The dropped log-broadcast on re-entry is the right tradeoff: we'd only be re-entering because Broadcast just failed, which means the ws clients aren't going to see this log line anyway. Better one lost diagnostic line than a crashed service.

On testing

No unit test included. EventBroadcaster is a static class tightly coupled to WebSocketSharp.Server and the 7DTD Log type (already called out as game-runtime-only in ModEventBusTests.cs:97). The actual recursion only happens when _server is non-null AND Broadcast throws, neither of which is reachable from the existing test harness without restructuring the class. The fix is small and the failure mode is reproducible in vivo — verifying the absence of recursion in prod logs after deploy is the better signal.

Test plan

  • Build passes on Windows .NET Framework 4.8
  • Deploy to prod box (72D-ADA → kitsuneden-prod)
  • Trigger a GracefulRestart and confirm no "stack overflow" lines in log
  • Confirm WS clients still get log broadcasts during normal operation

🤖 Generated with Claude Code

EventBroadcaster.Initialize subscribed to LogCallbackEvent with
`e => Broadcast("LogCallback", e)`. Broadcast's catch block called
Log.Warning(...) on failure. On 7DTD, Log.Warning fires another
LogCallbackEvent through the same bus -> re-enters this subscriber
-> Broadcast throws again -> Log.Warning again -> infinite recursion
-> stack overflow -> KC crashes.

The throw is reliably reproducible during shutdown: once the
WebSocketServer manager has stopped, _server.WebSocketServices...
.Broadcast(json) raises "The current state of the manager is not
Start." Observed live on a Windows prod box -- 65+ minutes after a
botched auto-start, KC's GracefulRestart wedge cascade ended in
"Error in event handler for LogCallbackEvent: The requested operation
caused a stack overflow." repeated dozens of times in the log,
crashing KC and forcing a service auto-restart.

Fix, scoped narrowly to the LogCallbackEvent path:

1. [ThreadStatic] _inLogBroadcast re-entrancy guard. Only on the
   LogCallback path -- other event types don't loop back into the
   logger from their failure handler, so they keep the existing
   Log.Warning-on-failure to surface real broadcast bugs.

2. Pulled the LogCallbackEvent subscriber out into a named
   BroadcastLogCallback method so the guard logic stays readable
   instead of being inlined in a lambda. Sets the flag, calls
   Broadcast, clears the flag in finally.

3. Broadcast<T> gains a suppressFailureLogging parameter. When true
   (LogCallbackEvent path), the catch falls back to
   Console.Error.WriteLine instead of Log.Warning so the failure
   notification itself cannot fire a fresh LogCallbackEvent and
   restart the recursion. Wrapped in its own try/catch in case
   stderr is also unhappy during shutdown.

The dropped log-broadcast on re-entry is the right tradeoff: we'd
only be re-entering because Broadcast just failed, which means the
ws clients aren't going to see this log line anyway. Better one lost
diagnostic line than a crashed service.

No unit test included. EventBroadcaster is a static class tightly
coupled to WebSocketSharp.Server and the 7DTD Log type (already
called out as game-runtime-only in ModEventBusTests.cs:97). The
actual recursion only happens when _server is non-null AND Broadcast
throws, neither of which is reachable from the existing test harness
without restructuring the class. The fix is small and the failure
mode is reproducible in vivo -- verifying the absence of recursion
in prod logs after deploy is the better signal.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
@AdaInTheLab
AdaInTheLab merged commit 4bbfa0c into main Jun 3, 2026
2 checks passed
@codecov

codecov Bot commented Jun 3, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

@AdaInTheLab
AdaInTheLab deleted the fix/log-callback-reentrancy branch June 4, 2026 00:21
AdaInTheLab added a commit that referenced this pull request Jun 4, 2026
Cuts v2.8.2. Three fixes from the live Windows prod box plus the
timezone field on the Server Restart panel grows up into a host-
resolvable dropdown. No new pages, no schema changes — patch release
per docs/RELEASES.md conventions.

What lands:

- #101 fix(websocket): stop LogCallbackEvent broadcast recursion in
  shutdown. ThreadStatic re-entrancy guard + suppressFailureLogging
  fallback to Console.Error so a failed log-broadcast can't fire a
  fresh LogCallbackEvent and recurse to stack overflow.
- #102 fix(restart): skip systemctl probe on Windows; route through
  OS-aware strategy. New Core/OsRestartStrategy.cs picks per OS;
  Windows goes straight to in-game shutdown + NSSM AppExit Restart
  bounce, no more wasted 5s probe or misleading warning.
- #103 feat(restart): host-resolvable timezone dropdown + heal-on-read.
  LoadPersistedSettings heals an unresolvable TZ ID to TimeZoneInfo
  .Local and persists. New GET /api/server/timezones endpoint feeds a
  PrimeVue Select in Settings → Server Restart, replacing the free-
  text input that admins kept filling with strings the host couldn't
  parse.

Version bumps:
- src/KitsuneCommand/ModInfo.xml: 2.8.1 → 2.8.2
- frontend/package.json: 2.7.4 → 2.8.2 (reconciles prior drift —
  frontend version was stuck at 2.7.4 since v2.8.0)
- CHANGELOG.md: promote [Unreleased] → [2.8.2] - 2026-06-04

Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant