perf(plugin): yield the sweep on a time budget, and measure loop lag per worker

[harper-joseph]

Two changes: a fix for a constant that went stale, and the instrumentation to prove whether the fix mattered.

The sweep holds the event loop for ~11ms at a time

It yielded every 200 rows. That was chosen when bench/queue-index measured a row at ~2.4 µs — 200 rows is ~0.5ms of held loop, invisible beside a ~1.6ms cache hit. On the production corpus a row costs ~55 µs, so those same 200 rows hold the loop for ~11ms. The sweep runs on a worker that also serves bot traffic, so every crawler request landing inside a slice waits for it.

The for await doesn't help: awaiting a promise that resolves on a microtask drains the microtask queue without returning to the poll phase. Only the setImmediate lets I/O callbacks run.

A row count cannot express "do not stall a request." It now yields on elapsed time — queue.ready.yieldBudget, default 2ms, set just above the ~1.6ms a cache hit takes to serve, so a request delayed by the sweep waits about as long as answering it would have taken. The clock is sampled every 32 rows rather than every row: at ~55 µs/row a per-row read is free, but the entire reason this is being rewritten is that a per-row cost moved 20×, and at 2.4 µs/row a per-row clock read would be ~2%.

This is the same class of bug as the sweepCap waste in v0.52.0 — a constant sized against a per-row cost that turned out 20× higher. Two in two releases, which is why the budget is expressed in time: it re-derives itself when the corpus changes instead of needing a human to notice.

The evidence stops short of proof, so this also measures it

Bot-facing duration (path: 'p') on the live fleet, per worker — these rows are per-thread:

	most workers	five workers
median	1.6ms	1.6ms
p95	2.4–3.1ms	2.7–3.0ms
p99	3.6–7.4ms	13.5, 43.3, 48.9, 50.6, 53.3ms

Median flat, p95 flat, p99 blown out 10–30× is the signature of intermittent loop blocking — it only touches the fraction of requests landing inside a stall.

But the sweep self-gates to workerIndex === 0, and the tail covers five workers. So this is consistent with the sweep and cannot be pinned on it: the queue-status sync, the reconciler, the sitemap refresh and GC are all indistinguishable in that data. The p99s also reach 43–53ms, above the ~11ms the arithmetic predicts — plausible, since 55 µs/row is an average and a batch that misses the block cache hits disk through a synchronous native binding, but plausible is not measured.

So prerender_ops event_loop_lag reports libuv's own histogram per worker (p99 and max, dimensioned by worker index), from every worker rather than pinned to one. That last part is the whole point — a cluster-wide number averages away exactly the signal being looked for. Whatever only worker 0 does then shows up only on worker 0, and queue.ready.yieldBudget becomes a knob you can turn against a number instead of a hypothesis.

monitorEventLoopDelay rather than the usual setTimeout-drift trick: it samples in libuv at 20ms and costs nothing measurable, where a JS timer both competes for the loop it is measuring and misses any stall shorter than its own interval.

Testing

785 pass / 0 fail.

The sweep test pins the invariant that matters for a scheduling change: the yield budget changes when the walk pauses and never what it publishes. Same corpus at a 1ms budget (yields on nearly every check) and at 1e9ms (never yields) must produce identical scanned, due, published and the same granted jobs in the same order.

readLag is extracted and tested rather than left inline, because its failure is silent and fleet-wide: an empty window returns Infinity from percentile(), and recordAnalytics aggregates by mean — so a single Infinity makes the merged row's mean Infinity for that period across every worker. The series would read as catastrophic while nothing was wrong, and that gets found from a dashboard weeks later. Tests cover empty, half-empty, NaN, and the case that must not be dropped: a genuine zero-lag window, since dropping it would make an idle worker indistinguishable from a broken monitor.

Rollout note

event_loop_lag emits 2 rows per worker per window (default 60s), so 32 rows/node/minute at 16 workers. management.eventLoopLagInterval: 0 disables it. The yield change needs no config to take effect and queue.ready.yieldBudget is live-reloadable.

Expect this to slightly increase total sweep wall time — more yields means more trips through the loop — while reducing the worst-case latency any single request behind it pays. That is the intended trade, and ready_sweep_ms against event_loop_lag is how to see both halves.

Lint: the three no-unused-vars errors are pre-existing on main in packages/console/test/trafficView.test.js.

🤖 Generated with Claude Code

[gemini-code-assist]

Code Review

This pull request introduces a per-worker event-loop lag monitor using Node's monitorEventLoopDelay to help diagnose event-loop blocking, and refactors the ready-set sweep to yield based on an elapsed time budget rather than a fixed row count. The review feedback highlights critical issues in the event-loop lag monitor implementation, including a bug that prevents live-reloading if disabled at startup, potential integer overflow from bitwise coercion on large intervals, and the need to flush remaining histogram data when the monitor is disabled.

[gemini-code-assist]

There are three issues with the current implementation of startEventLoopLagMonitor:

1. Startup Disabled Bug: If config.management.eventLoopLagInterval is 0 (disabled) at startup, the function returns early on line 61. This prevents onConfigApplied from being registered, meaning the monitor can never be enabled at runtime without a full process restart, violating the live-reload contract.
2. Bitwise Coercion Issue: Using | 0 on config.management.eventLoopLagInterval can wrap large values (greater than 2^31 - 1) to negative numbers, which Math.max(0, ...) then clamps to 0, disabling the timer entirely instead of using the configured interval. We should avoid bitwise coercion and use Math.floor instead.
3. Missing Flush on Disable: When disabling the periodic timer via live configuration changes, we must ensure we stop the timer and flush any remaining buffered data or counters one last time to prevent partial interval data from being silently lost.

We can resolve these issues by registering onConfigApplied unconditionally, using Math.floor instead of bitwise coercion, and flushing the remaining histogram data when disabling the monitor.

export function startEventLoopLagMonitor() {
	if (started) return;
	started = true;

	const interval = () => Math.max(0, Math.floor(config.management.eventLoopLagInterval || 0));
	let histogram = null;
	let timer = null;
	let armed = 0;

	const report = () => {
		if (!histogram) return;
		const lag = readLag(histogram);
		histogram.reset();
		if (lag.p99 !== undefined) metrics.eventLoopLag(lag.p99, 'p99', server.workerIndex);
		if (lag.max !== undefined) metrics.eventLoopLag(lag.max, 'max', server.workerIndex);
	};

	const sync = () => {
		const nextInterval = interval();
		if (nextInterval === armed) return;

		if (timer) {
			clearInterval(timer);
			timer = null;
			if (nextInterval === 0) {
				report();
			}
		}

		armed = nextInterval;
		if (armed > 0) {
			if (!histogram) {
				histogram = monitorEventLoopDelay({ resolution: 20 });
				histogram.enable();
			}
			timer = setInterval(report, Math.min(2147483647, armed));
			timer.unref?.();
		} else if (histogram) {
			histogram.disable();
			histogram = null;
		}
	};

	sync();
	onConfigApplied(sync);
}

References

1. In Node.js, clamp or validate configuration options representing timeouts or delays passed to setInterval or setTimeout to not exceed 2147483647 to avoid unexpected hot loops, and avoid using bitwise coercion (e.g., | 0) for large numbers.
2. When disabling a periodic timer or stats collector via live configuration changes, ensure to stop the timer and flush any remaining buffered data or counters one last time to prevent partial interval data from being silently lost.