fix(tui): classify a long loop block by CPU time instead of duration

The watchdog discarded every overshoot longer than `sleepMs` (60s) as
system sleep, on the rationale that "the process could not have run JS
during the missed interval". That is true for a suspended process and
false for a CPU-bound wedge, which is exactly the case where JS ran the
whole interval at 100% CPU.

Duration cannot separate the two: both produce an arbitrarily large gap.
Keying the suppression on magnitude therefore dropped the most severe
stalls and kept only the mild ones, so the probe went quiet precisely
when it had something to report. Issue #5372 shows an 82,391ms block that
16.4.8 logged and current builds do not.

Classify by mechanism instead. `cpuNow()` reads process CPU time, and an
over-`sleepMs` gap is suppressed only when the process also burned less
than half of it on CPU. A resumed process shows a gap it did not spend
CPU on; a wedged one shows a gap it spent almost entirely on CPU. The
observed CPU time is included in the log line so a reader can tell which
kind of stall they are looking at.

Refs #5372, #7328, #6145

packages/tui/src/loop-watchdog.ts

@@ -6,10 +6,12 @@ export interface LoopWatchdogOptions {
 	intervalMs?: number;
 	/** A tick later than this past its deadline counts as a block. Default 250. */
 	thresholdMs?: number;
-	/** Overshoot beyond this likely includes system sleep, so it is suppressed. Default 60_000. */
+	/** Overshoot beyond this is suppressed only when the process also burned no CPU. Default 60_000. */
 	sleepMs?: number;
 	/** Monotonic clock source; injectable for tests. Default `performance.now`. */
 	now?: () => number;
+	/** Process CPU time in ms; injectable for tests. Default `process.cpuUsage`. */
+	cpuNow?: () => number;
 	/** Timer source; injectable for tests. Default `setTimeout`. */
 	schedule?: (cb: () => void, ms: number) => LoopWatchdogTimer;
 }
@@ -23,6 +25,15 @@ interface LoopWatchdogTimer {
 	cancel?(): void;
 }
 
+/**
+ * Fraction of a missed interval that must show up as CPU time for the overshoot
+ * to count as a synchronous stall rather than system sleep. A suspended process
+ * resumes having burned essentially nothing; a wedged one burned the interval on
+ * a core. Half leaves room for a gap that is partly sleep and partly work, which
+ * is still worth reporting.
+ */
+const CPU_BUSY_RATIO = 0.5;
+
 /**
  * Always-on event-loop lag probe. Each tick is scheduled `intervalMs` ahead of
  * a recorded deadline; a tick that fires `thresholdMs` past its deadline means
@@ -35,18 +46,22 @@ interface LoopWatchdogTimer {
  * The handle is `unref`'d so the probe never keeps the process alive, and stop()
  * cancels the armed timer when the handle exposes `cancel` (the default
  * `setTimeout` handle does, via `clearTimeout`). The `#generation` guard remains
- * as a fallback for injected handles that cannot cancel. An overshoot beyond
- * `sleepMs` is treated as system sleep rather than a synchronous stall: the
- * process could not have run JS during the missed interval, and one resume
- * should not produce a multi-minute `ui.loop-blocked` record.
+ * as a fallback for injected handles that cannot cancel.
+ *
+ * A long overshoot is classified by CPU time rather than by duration. System
+ * sleep and a CPU-bound wedge both produce an arbitrarily large gap, so duration
+ * alone cannot tell them apart, and suppressing on duration discards exactly the
+ * worst stalls. Only a gap the process did not spend CPU on is treated as sleep.
  */
 export class LoopWatchdog {
 	#intervalMs: number;
 	#thresholdMs: number;
 	#sleepMs: number;
 	#now: () => number;
+	#cpuNow: () => number;
 	#schedule: (cb: () => void, ms: number) => LoopWatchdogTimer;
 	#expected = 0;
+	#expectedCpu = 0;
 	#wasBlocked = false;
 	#running = false;
 	// Bumped by stop(); each scheduled tick captures the generation it was armed
@@ -60,6 +75,12 @@ export class LoopWatchdog {
 		this.#thresholdMs = options.thresholdMs ?? 250;
 		this.#sleepMs = options.sleepMs ?? 60_000;
 		this.#now = options.now ?? (() => performance.now());
+		this.#cpuNow =
+			options.cpuNow ??
+			(() => {
+				const usage = process.cpuUsage();
+				return (usage.user + usage.system) / 1000;
+			});
 		this.#schedule =
 			options.schedule ??
 			((cb, ms) => {
@@ -86,6 +107,7 @@ export class LoopWatchdog {
 	#armTick(): void {
 		const generation = this.#generation;
 		this.#expected = this.#now() + this.#intervalMs;
+		this.#expectedCpu = this.#cpuNow();
 		this.#handle = this.#schedule(() => this.#tick(generation), this.#intervalMs);
 		this.#handle.unref?.();
 	}
@@ -93,17 +115,20 @@ export class LoopWatchdog {
 	#tick(generation: number): void {
 		if (!this.#running || generation !== this.#generation) return;
 		const blockedMs = this.#now() - this.#expected;
+		const cpuMs = this.#cpuNow() - this.#expectedCpu;
 		// Consume the recent phase every tick (block or not) so attribution is
 		// scoped to the just-elapsed interval and never carries a stale phase
 		// forward to a later, phase-less block.
 		const phase = takeRecentLoopPhase();
 		if (blockedMs > this.#thresholdMs) {
-			if (blockedMs > this.#sleepMs) {
+			if (blockedMs > this.#sleepMs && cpuMs < blockedMs * CPU_BUSY_RATIO) {
+				// A long gap the process did not spend CPU on: it was suspended.
 				this.#wasBlocked = false;
 			} else if (!this.#wasBlocked) {
 				this.#wasBlocked = true;
 				logger.warn("ui.loop-blocked", {
 					blockedMs: Math.round(blockedMs),
+					cpuMs: Math.round(cpuMs),
 					phase: phase ?? "unknown",
 				});
 			}

packages/tui/test/loop-watchdog.test.ts

@@ -94,7 +94,7 @@ describe("LoopWatchdog", () => {
 		const { wd, setNow, fireTick } = harness({ sleepMs: 5_000 });
 
 		wd.start(); // deadline at 250
-		setNow(10_250); // blockedMs = 10_000 exceeds the sleep cutoff
+		setNow(10_250); // blockedMs = 10_000 exceeds the sleep cutoff, and no CPU was burned
 		fireTick();
 
 		expect(warnSpy).not.toHaveBeenCalled();
@@ -225,3 +225,77 @@ describe("LoopWatchdog", () => {
 		expect(cancel).toHaveBeenCalledTimes(1);
 	});
 });
+
+/**
+ * A long overshoot is classified by CPU time, not by duration. System sleep and
+ * a CPU-bound wedge both produce an arbitrarily large gap, so duration alone
+ * cannot separate them — and suppressing on duration discards exactly the worst
+ * stalls. Issue #5372 reported an 82,391ms block that older builds logged and
+ * current builds drop silently.
+ */
+describe("LoopWatchdog long-block classification", () => {
+	function cpuHarness(options: Partial<{ intervalMs: number; thresholdMs: number; sleepMs: number }> = {}) {
+		let nowValue = 0;
+		let cpuValue = 0;
+		let scheduled: (() => void) | undefined;
+		const wd = new LoopWatchdog({
+			now: () => nowValue,
+			cpuNow: () => cpuValue,
+			schedule: (cb: () => void) => {
+				scheduled = cb;
+				return {};
+			},
+			...options,
+		});
+		return {
+			wd,
+			set(now: number, cpu: number): void {
+				nowValue = now;
+				cpuValue = cpu;
+			},
+			fireTick(): void {
+				const cb = scheduled;
+				if (!cb) throw new Error("no tick was scheduled");
+				cb();
+			},
+		};
+	}
+
+	test("reports a CPU-bound wedge longer than sleepMs instead of discarding it", () => {
+		const warnSpy = vi.spyOn(logger, "warn").mockImplementation(() => {});
+		const h = cpuHarness();
+
+		h.wd.start(); // deadline 250, cpu baseline 0
+		// 82,391ms of wall clock, essentially all of it burned on a core.
+		h.set(82_641, 82_000);
+		h.fireTick();
+
+		expect(warnSpy).toHaveBeenCalledTimes(1);
+		const ctx = warnSpy.mock.calls[0]![1] as { blockedMs: number; cpuMs: number };
+		expect(ctx.blockedMs).toBe(82_391);
+		expect(ctx.cpuMs).toBeGreaterThan(80_000);
+	});
+
+	test("still suppresses a suspend/resume gap of the same duration", () => {
+		const warnSpy = vi.spyOn(logger, "warn").mockImplementation(() => {});
+		const h = cpuHarness();
+
+		h.wd.start();
+		// Same wall gap, but the process was suspended: no CPU consumed.
+		h.set(82_641, 3);
+		h.fireTick();
+
+		expect(warnSpy).not.toHaveBeenCalled();
+	});
+
+	test("reports a long block that spent most, but not all, of the gap on CPU", () => {
+		const warnSpy = vi.spyOn(logger, "warn").mockImplementation(() => {});
+		const h = cpuHarness();
+
+		h.wd.start();
+		h.set(120_250, 90_000);
+		h.fireTick();
+
+		expect(warnSpy).toHaveBeenCalledTimes(1);
+	});
+});