From 06289026440e913fd2c385d8dbb1958e0756c37b Mon Sep 17 00:00:00 2001
From: Kamron Batman <3953314+kamronbatman@users.noreply.github.com>
Date: Sun, 9 Aug 2026 22:05:18 -0700
Subject: [PATCH] fix: harden idle-sleep scheduling against bad config and
misattributed saves (#2567)
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit
Follow-ups to #2559, from a review of the ported idle-sleep/scheduler-health changes.
### Fixes
- **`NetState.IsIdle` omitted `_pendingDisconnects`** — `Slice()` drains five queues; the property checked four. The other deferred work (`_connectingQueue`, alive checks, movement throttle) is time-gated and correctly excluded; the disconnect queue was the only ready-work omission. Impact was bounded (≤ one idle wait of delay), but the property's contract is "sleeping cannot strand pending work".
- **Neither new setting was clamped** (`Main.cs`):
- `server.lateWakeThreshold: -1` made `late <= threshold` false for every sample even at zero late wakes, so from the second sample on, sleeping was re-suspended every second, forever — a permanent full-core spin whose only trace was a nonsense warning ("… at least 8ms late 0 time(s)").
- `server.eventLoopIdleWaitMs: -1` disabled sleeping while the admin gump reported **Healthy** (it tested `== 0`).
- Both now clamp to `>= 0` and log a warning naming the configured value. `-1` is a natural thing to reach for given the sibling key's doc says "set very high to disable".
- **World snapshots were misattributed to `StolenMs`** — `World.Snapshot` ran outside all five profiler phases, so a 3-second save inside a sample read as ~75% stolen, and `debugging-event-loop.md` teaches stolen = "the host ran something else". The diagnostic pointed operators at buying dedicated CPU for their own largest loop-thread stall. Saves now land in a new `WorldSnapshot` phase; `[LoopStats` iterates `PhaseCount` generically, so the report and CSV pick it up with no changes.
- **Admin gump conflated host-forced spin with configured spin** — when the startup probe finds no high-resolution wait support it zeroes the idle wait, after which the gump said "Spinning (configured)" and the operator's config said 2. New `Core.IdleSleepUnsupported` property; the gump now shows "Spinning - host cannot honor short waits" as a distinct fourth verdict. A genuinely configured 0 still reads "configured" (the probe only runs when the configured value was > 0).
- **The backoff-ceiling `Error` logged once per process lifetime** — `_loggedBackoffCeiling` never reset, and at the ceiling the method returns before the `Warning`, so a host that recovered (>60s clean streak) and later degraded back to the ceiling never re-logged the one operator-actionable message. The flag now resets with the clean-streak escalation reset.
- **Removed the unreachable "already suspended, extend" branch** — no sleeps occur while suspended, so `_lateWakes` stays 0 and every suspended sample early-returns before reaching it; with the threshold clamped it can never fire. If sleep gating ever changes, the normal path handles the case by counting a fresh episode.
`dev-docs/debugging-event-loop.md` updated to match (phase list + gump verdict table).
### Verification
- `dotnet build` clean (0 warnings) both normally and with `-p:EventLoopProfiling=true` (the snapshot phase only becomes live IL under the profiling flag).
---
.../Server/Diagnostics/EventLoopProfiler.cs | 3 +-
Projects/Server/Main.cs | 42 ++++++++++++++-----
.../Network/NetState/NetState.Network.cs | 2 +-
Projects/UOContent/Gumps/AdminGump.cs | 3 +-
dev-docs/debugging-event-loop.md | 5 ++-
5 files changed, 40 insertions(+), 15 deletions(-)
diff --git a/Projects/Server/Diagnostics/EventLoopProfiler.cs b/Projects/Server/Diagnostics/EventLoopProfiler.cs
index a3fd157f5..615a84afd 100644
--- a/Projects/Server/Diagnostics/EventLoopProfiler.cs
+++ b/Projects/Server/Diagnostics/EventLoopProfiler.cs
@@ -26,6 +26,7 @@ public enum LoopPhase
TimerSlice,
NetworkSlice,
LoopTasks,
+ WorldSnapshot,
}
///
@@ -42,7 +43,7 @@ public enum LoopPhase
///
public static class EventLoopProfiler
{
- public const int PhaseCount = 5;
+ public const int PhaseCount = 6;
private const int RingSize = 900;
private const long SampleIntervalMs = 1000;
diff --git a/Projects/Server/Main.cs b/Projects/Server/Main.cs
index eb95e6d4e..620d67c28 100644
--- a/Projects/Server/Main.cs
+++ b/Projects/Server/Main.cs
@@ -57,6 +57,12 @@ public static class Core
///
public static int EventLoopIdleWaitMs => _eventLoopIdleWaitMs;
+ ///
+ /// True when idle sleeping was disabled at startup because the host cannot honor short
+ /// waits, overriding whatever server.eventLoopIdleWaitMs was configured to.
+ ///
+ public static bool IdleSleepUnsupported { get; private set; }
+
///
/// Whether idle sleeping is currently suspended because the host returned waits late.
///
@@ -129,18 +135,13 @@ public static class Core
return;
}
- // Already suspended: extend rather than counting a fresh backoff episode.
- if (_tickCount - _idleSleepSuspendedUntil < 0)
- {
- _idleSleepSuspendedUntil = _tickCount + _currentBackoffMs;
- return;
- }
-
- // A long clean streak resets the escalation. Gated on the count rather than a
+ // A long clean streak resets the escalation, re-arming the ceiling Error so a host that
+ // recovers and later degrades again gets re-reported. Gated on the count rather than a
// "_lastBackoffAt > 0" sentinel because tick counts are not guaranteed positive.
if (_consecutiveBackoffs > 0 && _tickCount - _lastBackoffAt > BackoffResetAfterCleanMs)
{
_consecutiveBackoffs = 0;
+ _loggedBackoffCeiling = false;
}
_currentBackoffMs = Math.Min(BackoffBaseMs << Math.Min(_consecutiveBackoffs, BackoffMaxShift), BackoffMaxMs);
@@ -553,11 +554,29 @@ public static class Core
ServerConfiguration.Load();
// 0 disables idle sleeping entirely (full-core spin, zero scheduling overhead).
- _eventLoopIdleWaitMs = ServerConfiguration.GetSetting("server.eventLoopIdleWaitMs", 2);
+ var idleWaitMs = ServerConfiguration.GetSetting("server.eventLoopIdleWaitMs", 2);
+ if (idleWaitMs < 0)
+ {
+ logger.Warning(
+ "server.eventLoopIdleWaitMs {Value} is negative; using 0 (idle sleeping disabled)",
+ idleWaitMs
+ );
+ }
+
+ _eventLoopIdleWaitMs = Math.Max(0, idleWaitMs);
// 16ms-budget misses per second before idle sleeping backs off. Raise to tolerate a
// jittery host; set very high to disable the backoff.
- _lateWakeThreshold = ServerConfiguration.GetSetting("server.lateWakeThreshold", 1);
+ var lateWakeThreshold = ServerConfiguration.GetSetting("server.lateWakeThreshold", 1);
+ if (lateWakeThreshold < 0)
+ {
+ logger.Warning(
+ "server.lateWakeThreshold {Value} is negative; using 0",
+ lateWakeThreshold
+ );
+ }
+
+ _lateWakeThreshold = Math.Max(0, lateWakeThreshold);
var assemblyPath = Path.Join(BaseDirectory, AssembliesConfiguration);
@@ -621,6 +640,7 @@ public static class Core
"resolution failed). Idle sleeping is disabled. The loop will spin instead, using a full core."
);
+ IdleSleepUnsupported = true;
_eventLoopIdleWaitMs = 0;
}
@@ -672,8 +692,10 @@ public static class Core
if (_performSnapshot)
{
+ EventLoopProfiler.PhaseStart(LoopPhase.WorldSnapshot);
// Return value is the offset that can be used to fix timers that should drift
World.Snapshot(_snapshotPath);
+ EventLoopProfiler.PhaseEnd(LoopPhase.WorldSnapshot);
_performSnapshot = false;
}
diff --git a/Projects/Server/Network/NetState/NetState.Network.cs b/Projects/Server/Network/NetState/NetState.Network.cs
index 9cb7b85fb..f69f92076 100644
--- a/Projects/Server/Network/NetState/NetState.Network.cs
+++ b/Projects/Server/Network/NetState/NetState.Network.cs
@@ -87,7 +87,7 @@ public partial class NetState
///
internal static bool IsIdle =>
_throttled.Count == 0 && _throttledPending.Count == 0 &&
- _flushPending.Count == 0 && _disposed.Count == 0;
+ _flushPending.Count == 0 && _pendingDisconnects.Count == 0 && _disposed.Count == 0;
///
/// Gets the listening addresses that the server is bound to.
diff --git a/Projects/UOContent/Gumps/AdminGump.cs b/Projects/UOContent/Gumps/AdminGump.cs
index 130d031fc..a4fbe0f18 100644
--- a/Projects/UOContent/Gumps/AdminGump.cs
+++ b/Projects/UOContent/Gumps/AdminGump.cs
@@ -227,7 +227,8 @@ namespace Server.Gumps
}
case AdminGumpPage.Information_Perf:
{
- var loopStatus = Core.EventLoopIdleWaitMs == 0 ? "Spinning (configured)" :
+ var loopStatus = Core.IdleSleepUnsupported ? "Spinning - host cannot honor short waits" :
+ Core.EventLoopIdleWaitMs == 0 ? "Spinning (configured)" :
Core.IdleSleepSuspended ? "Sleep suspended - host returning waits late" : "Healthy";
AddLabel(20, 130, LabelHue, "Event Loop:");
diff --git a/dev-docs/debugging-event-loop.md b/dev-docs/debugging-event-loop.md
index 5c5ea3b63..8b5fdcf36 100644
--- a/dev-docs/debugging-event-loop.md
+++ b/dev-docs/debugging-event-loop.md
@@ -8,7 +8,8 @@ funnel in order; most incidents resolve before the last step. Do not start with
Every second of the main thread's wall time goes to exactly one of four places:
1. **Work** — the loop's phases: mobile deltas, item deltas, timer callbacks (`Timer.Slice`),
- network processing (`NetState.Slice`), posted tasks (`LoopContext`).
+ network processing (`NetState.Slice`), posted tasks (`LoopContext`), world snapshots
+ (`WorldSnapshot` — the on-loop portion of a save).
2. **Sleep** — idle blocking in `NetState.WaitForCompletion`, bounded by the next timer tick and
`server.eventLoopIdleWaitMs`.
3. **GC pauses** — land inside whichever phase (or sleep) was running.
@@ -27,7 +28,7 @@ No build changes needed. Three signals exist, all actionable:
|---|---|---|
| Startup error: *host cannot honour short waits* | No high-resolution timer and `timeBeginPeriod` failed. Very old or unusual Windows. | Nothing is wrong with the server; it spins and uses a full core. Upgrade the OS or accept the core. |
| Warning: *host returned a Nms idle wait late* + sleeping suspended | The OS did not reschedule the process promptly after a 1–2ms wait. Shared/burstable vCPU signature. | Move to dedicated CPU, or set `server.eventLoopIdleWaitMs=0` to spin permanently. This is a **host** problem — no amount of server-side change fixes it. |
-| Admin gump → Performance → *Event Loop* | `Healthy` / `Sleep suspended (host)` / `Spinning (configured)` | Same as above. |
+| Admin gump → Performance → *Event Loop* | `Healthy` / `Sleep suspended (host)` / `Spinning (configured)` / `Spinning - host cannot honor short waits` | Same as above; the last verdict is the startup error's state, not a config choice. |
If none of these fired and the shard still feels laggy, the cause is work, GC, or something a
boot-time signal cannot see. Continue.