6d846b11e5
## Problem
`RunEventLoop` span through its body regardless of whether there was anything to do — ~10% of a desktop core for an empty shard, and ~70% of a core on a 3 vCPU VPS. A process that never idles is exactly what burstable vCPU plans throttle, which is how this surfaced: lag spikes that went away when the operator bought more cores. The spin also denied the GC its natural pause points, so memory climbed until a world save forced a collection — alarming in task manager, harmless in practice, and a recurring source of "is my server leaking?" reports.
## Result
Windows desktop, real world of **190,728 items / 33,158 mobiles**, no players, saves and prebake off, three consecutive runs:
| | Legacy spin | Idle sleeping |
|---|---|---|
| **CPU** | 10.42 – 10.50% of one core | **0.78 – 1.00%** |
| **Tick lag** (peak/15s) | 4–10 ms | 5–11 ms |
**~10× less CPU with tick lag unchanged** — the CPU came free rather than being traded for latency. Slower hosts gain proportionally more. Spin mode (`server.eventLoopIdleWaitMs=0`) independently gained **7× the iterations per core** (1.19M → 8.3M cycles/sec) from the ring's AcceptEx rework.
## How
The loop blocks in `NetState.WaitForCompletion` whenever every queue it drains is empty (all the drains are bounded, so leftovers keep it awake). Receive completions, new connections, and cross-thread `LoopContext.Post` (via the ring's sticky `Wake()`) are all in the wait set, so sleeping adds no latency to any of them. Only timer-driven logic sees wheel lag, bounded by the idle wait.
**Health is measured at the only place sleeping can cause harm.** A sleep is bounded by the time to the next wheel turn, so a correctly honoured sleep can never miss a deadline — the only failure mode is the host returning the wait late. That overshoot is measured on every sleep (one extra timestamp read; production's entire accounting cost), and an escalating backoff suspends sleeping when it persists. By construction, server work — saves, heavy staff commands, deep timer callbacks — cannot trip it, so the warning means exactly one thing: *the host is not scheduling the process promptly*, with two known remedies (dedicated CPU, or `=0`). Hosts with no high-resolution wait mechanism at all are detected once at startup and spin instead.
**CPS is removed.** `Core.CyclesPerSecond`/`AverageCPS` measured nothing actionable before and became actively misleading once the loop sleeps (the rate is set by the sleep, not by shard health). The admin gump's Performance page now shows the verdict instead: `Healthy` / `Sleep suspended (host)` / `Spinning (configured)`.
## Configuration
| Setting | Default | Meaning |
|---|---|---|
| `server.eventLoopIdleWaitMs` | `2` | Longest idle block. Measured across 1/2/4/8 ms, 2 is where the trade stops being free. `0` = never sleep: ~98% of a core, zero scheduling overhead — for large shards on dedicated CPU. |
| `server.lateWakeThreshold` | `1` | Idle waits the host may return a full tick late, per second, before sleeping backs off. Raise for jittery hosts; very high disables the backoff. |
## Diagnostics (compiled out by default)
`dotnet build -p:EventLoopProfiling=true` compiles in `EventLoopProfiler` — every hook is `[Conditional("EVENT_LOOP_PROFILING")]`, so normal builds contain zero profiling IL. The profiling build decomposes each second of wall time into **work (per loop phase) / sleep / GC pause / stolen residual**, keeps ~15 minutes of history in a ring buffer, and the `[LoopStats` command prints the last minute and dumps the full history to CSV. `dev-docs/debugging-event-loop.md` is the diagnosis guide (for humans and AI): what production already tells you, when to flip the profiling build, the signature table for host-steal vs deep-processing vs GC vs wake bugs, why dotnet-trace comes last, and the GC/RAM "leak" misconception.
## Verification
- 815 Server.Tests green; both build configurations compile.
- Docker echo harness green on epoll and io_uring (ping-pong mode); kqueue verified manually on an M1 Max.
- A/B measurements and per-change numbers: `measure/event-loop` branch.
## Notes
The full measurement harness and vendored ring sources used to develop this live on the [`measure/event-loop`](https://github.com/modernuo/ModernUO/tree/measure/event-loop) branch, kept for future loop work.
2.7 KiB
Tick Counts: Overflow and Huge Starting Values
Rules for any code that compares Core.TickCount / Core.GetTimestamp() values. Getting this
wrong produces bugs that only appear on specific cloud hosts after long host uptimes — the worst
kind to reproduce.
Why this matters (the Linux/cloud problem)
Core.GetTimestamp() is built on Stopwatch.GetTimestamp(), which on Linux reads the kernel's
monotonic clock — and on some hypervisors, notably Google Cloud, the VM receives a
pass-through of the host's never-resetting counter. The tick count is not zero when the
process starts and not zero when the operating system booted; it is however long the physical
host has been up, which can be months or years. We have been burned by this in production.
Consequences:
- Raw values are enormous from the first read. Arithmetic that would "never overflow in 292
years" of process uptime can overflow immediately (
Core.GetTimestamp()'sUInt128conversion path exists precisely becauseraw * 1000does not fit in 64 bits for large raws). - Wrapped values can be negative. Nothing may assume a tick count is positive.
- Windows is not affected in our testing so far, which is exactly why this class of bug ships: it works on every dev machine and fails on a customer's GCP instance.
The rules
-
Compare by subtraction, never directly. Subtraction of two ticks wraps correctly in two's complement; direct comparison does not.
// WRONG: fails when ticks wrap or start huge if (Core.TickCount < deadline) // RIGHT: wraparound-safe if (Core.TickCount - deadline < 0) -
Durations are always subtractions of two readings (
elapsed = end - start). Never derive a duration from a single absolute value. -
No zero or sign sentinels.
if (_lastEventAt > 0)as "has this happened yet" breaks when ticks are negative. Track "has happened" with a separateboolor an existing counter. -
Seed deadline fields from a real tick, not from field initialization. A
long _deadline;left at 0 compares wrong against a huge or negative tick. Initialize relative to the first observed timestamp (see the schedule-state seeding inCore.Setup). -
Store deadlines as
start + intervalonly if every comparison follows rule 1. The addition may wrap; the subtraction comparison handles it.
Reviewing for it
Grep the diff for TickCount <, TickCount >, GetTimestamp() <, and comparisons against any
field whose name suggests a deadline (*Until, *At, *Next*). Each hit must be in subtraction
form. DateTime/DateTimeOffset comparisons are unaffected; this applies only to the monotonic
tick domain.