diff --git a/CHANGELOG.md b/CHANGELOG.md index dbbeb3d..b321a8a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,26 @@ pulls notes from — it's the minimum, the GitHub release page is the maximum. ## [Unreleased] +### Fixed + +- **No more stack overflow from `LogCallbackEvent` re-entrancy during + shutdown.** `EventBroadcaster` subscribed to `LogCallbackEvent` and + broadcast each fired log message over the WebSocket. When KC was + mid-shutdown and the WebSocket manager had already stopped, the + inner `Broadcast` threw ("The current state of the manager is not + Start.") and the catch block called `Log.Warning(...)` — which fired + another `LogCallbackEvent`, re-entered the same subscriber, threw + again, logged again, and recursed until the stack overflowed and KC + crashed. Observed live on a Windows prod box: a botched + `GracefulRestart` left the WS manager stopped while the event bus + was still alive, and KC logged "Error in event handler for + LogCallbackEvent: The requested operation caused a stack overflow." + dozens of times before the service died. Fix: a `[ThreadStatic]` + re-entrancy guard scoped to the `LogCallbackEvent` path only (other + events don't loop back into the logger), and the failure path on + that path writes to `Console.Error` instead of `Log.Warning` so the + recursion can't restart. + ## [2.8.1] - 2026-05-29 > [Full notes](https://github.com/Kitsune-Den/KitsuneCommand/releases/tag/v2.8.1) diff --git a/src/KitsuneCommand/WebSocket/EventBroadcaster.cs b/src/KitsuneCommand/WebSocket/EventBroadcaster.cs index f6411b8..2ac1e63 100644 --- a/src/KitsuneCommand/WebSocket/EventBroadcaster.cs +++ b/src/KitsuneCommand/WebSocket/EventBroadcaster.cs @@ -15,6 +15,29 @@ public static class EventBroadcaster ContractResolver = new Newtonsoft.Json.Serialization.CamelCasePropertyNamesContractResolver() }; + /// + /// Thread-local re-entrancy guard for only. + /// + /// 7DTD routes its Log.* writes through the same logging chain that fires + /// LogCallbackEvent. If Broadcast() throws while handling a LogCallbackEvent + /// (typical during shutdown once the WebSocketServer manager has stopped: + /// "The current state of the manager is not Start.") and we then call + /// Log.Warning(...) to report it, that Log.Warning fires another + /// LogCallbackEvent, re-enters this subscriber, throws again, logs again, + /// and recurses until the stack overflows and KC crashes. + /// + /// Observed live on a Windows prod box: a botched GracefulRestart left the + /// WS manager stopped while the event bus was still alive, and KC logged + /// "Error in event handler for LogCallbackEvent: The requested operation + /// caused a stack overflow." dozens of times before the service died. + /// + /// Scope is intentionally narrow: other event types don't loop back into + /// the logger from their failure path, so they keep the normal + /// Log.Warning-on-failure behavior to surface real broadcast bugs. + /// + [ThreadStatic] + private static bool _inLogBroadcast; + public static void Initialize(WebSocketServer server, ModEventBus eventBus) { _server = server; @@ -32,7 +55,7 @@ public static void Initialize(WebSocketServer server, ModEventBus eventBus) eventBus.Subscribe(e => Broadcast("EntityKilled", e)); eventBus.Subscribe(e => Broadcast("ChatMessage", e)); eventBus.Subscribe(e => Broadcast("SkyChanged", e)); - eventBus.Subscribe(e => Broadcast("LogCallback", e)); + eventBus.Subscribe(BroadcastLogCallback); eventBus.Subscribe(e => Broadcast("PlayersPositionUpdate", e)); eventBus.Subscribe(e => Broadcast("PointsUpdate", e)); eventBus.Subscribe(e => Broadcast("BloodMoonVoteUpdate", e)); @@ -40,7 +63,33 @@ public static void Initialize(WebSocketServer server, ModEventBus eventBus) eventBus.Subscribe(e => Broadcast("TicketUpdated", e)); } - private static void Broadcast(string eventType, T data) + /// + /// Re-entrancy-safe LogCallbackEvent broadcaster. + /// + /// If we're already inside a LogCallbackEvent broadcast on this thread, + /// drop the event silently — anything we'd log here would just fire + /// another LogCallbackEvent and we'd be back to the recursion bug this + /// guard exists to prevent. Likewise, if the inner broadcast throws, + /// we deliberately do NOT route the failure through Log.Warning. + /// Console.Error.WriteLine is the closest we'll get to surfacing it, + /// and even that is wasted noise during shutdown — but it's bounded. + /// + internal static void BroadcastLogCallback(LogCallbackEvent e) + { + if (_inLogBroadcast) return; + + _inLogBroadcast = true; + try + { + Broadcast("LogCallback", e, suppressFailureLogging: true); + } + finally + { + _inLogBroadcast = false; + } + } + + private static void Broadcast(string eventType, T data, bool suppressFailureLogging = false) { if (_server == null) return; @@ -58,7 +107,25 @@ private static void Broadcast(string eventType, T data) catch (Exception ex) { // Don't let broadcast failures crash the game - Log.Warning($"[KitsuneCommand] Broadcast error for {eventType}: {ex.Message}"); + if (suppressFailureLogging) + { + // LogCallbackEvent path: Log.* feeds back into the broadcaster, + // so any logger call here is a recursion hazard. Use the bare + // Console.Error channel instead — bounded and won't re-enter. + try + { + Console.Error.WriteLine( + $"[KitsuneCommand] Broadcast error for {eventType}: {ex.Message}"); + } + catch + { + // Last-resort: stderr itself failed. Nothing safe left to do. + } + } + else + { + Log.Warning($"[KitsuneCommand] Broadcast error for {eventType}: {ex.Message}"); + } } } }