Repository navigation
perf(usage): yield with setImmediate, not a clamped setTimeout(0) - #10892
Conversation
The Claude usage scanner yielded to the event loop with setTimeout(resolve, 0), which Node clamps to ~1ms. Both batch loops yield once per 4 files, so a machine with 7.5k transcripts made ~3,800 yields and spent seconds parked on timers doing no work. The sibling codex-usage scanner already used setImmediate; this was an inconsistency, not a design choice. 82x on the yield path (4.3s -> 53ms at this machine's real 7,552 transcripts). Responsiveness -- the reason the yield exists -- improves rather than regresses: worst concurrent wait during a scan drops from 6.33ms to 0.12ms, because most of the old wall time was the main process idle-but-blocked on timer clamps. Left alone deliberately: the three setTimeout(0) sites in the PTY paste path (orca-runtime.ts, pty.ts) pace inter-chunk writes rather than merely yield, so removing the clamp there would change write pacing, not just scheduling. Co-authored-by: Orca <help@stably.ai>
📝 WalkthroughWalkthroughThe scanner’s 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches📝 Generate docstrings
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Actionable comments posted: 1
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro Plus
Run ID: 46c62c79-ed57-49f5-b5df-57cf2dc68a2b
📒 Files selected for processing (2)
config/scripts/claude-usage-yield-benchmark.mjssrc/main/claude-usage/scanner.ts
Review feedback: the yield count was wrong twice over. Each pass walks ceil(files / batch) batches and yields after every batch except the last, so a pass yields batchesPerPass - 1 times -- and the loop was being handed the yield count as a batch count, producing one fewer yield than the row claimed. Correcting it also exposed that the ratio is not a stable number to publish. The setImmediate arm is small enough (54-164 ms) that background load swings the ratio between 32x and 81x across runs, while the removed wall time holds at 4.2-5.1 s. Report the absolute saving alongside the ratio and say which to read. Co-authored-by: Orca <help@stably.ai>
|
Fixed in e32d931, and it forced a correction to this PR's headline number. The yield count was wrong twice over, exactly as you describe. Each pass walks Correcting it exposed something worse than an off-by-one: the ratio isn't a publishable number at all. Three consecutive runs of the corrected benchmark:
The Worth being explicit that this is the same class of mistake I hit on #10881 (a 23.3× that was really 6.7×) — there I fixed it by interleaving the arms, which this benchmark already did. Interleaving controls for drift between arms; it does nothing when one arm is so small that noise dominates it proportionally. Reporting the absolute delta is the actual fix. The underlying change is unaffected — one line, |
…ablyai#10892) Co-authored-by: Orca <help@stably.ai>
Description
The Claude usage scanner yielded to the event loop with
setTimeout(resolve, 0). Node clamps that to ~1ms. Both batch loops yield once perFILE_SCAN_BATCH_SIZE(4) files, so a machine with 7,552 transcripts makes ~3,800 yields and spends seconds parked on timers doing no work.setImmediateruns on the same tick's check phase with no clamp. The sibling scannersrc/main/codex-usage/scanner.ts:92already usedsetImmediate— this was an inconsistency, not a design choice. The two functions were otherwise byte-identical.One line changed.
ELI5
While scanning your usage history, the app pauses between small batches so the rest of the app stays responsive.
It was using a pause that Node rounds up to a full millisecond. Do that ~3,800 times and you've waited ~4 seconds doing nothing. The fix uses the pause that means "right after this tick," which is what was wanted all along.
Proof of perf improvement
config/scripts/claude-usage-yield-benchmark.mjs(new), arms alternated per round, per-arm medians:setTimeout(0)setImmediateRead the saved column, not the ratio. The
setImmediatearm is small enough that backgroundload lands almost entirely on it, swinging the ratio between 32× and 81× across three consecutive
runs while the removed wall time holds steady at 4.2–5.1 s. The honest headline is
~4.3 seconds of main-process wall time removed per full scan, not a multiple.
The yield count is derived from real data, not assumed: the benchmark counts
.jsonlfiles under~/.claude/projects(7,552 here) and readsFILE_SCAN_BATCH_SIZEand the yield-site count out of the scanner source.Independent confirmation of the mechanism, measured separately and in both orders:
setTimeout(0)costs 1,138 µs per yield versus 14.3 µs forsetImmediate.Responsiveness improves — it does not regress. That matters, because responsiveness is the entire reason the yield exists; a "faster" yield that starved other work would be a regression even at 80×. Measured with a concurrent probe task during a full scan:
setTimeout(0)setImmediateThe old version was worse on both axes because most of its wall time was the main process idle-but-blocked on timer clamps. The benchmark prints an explicit NOTE if
setImmediateever shows a worse concurrent wait, so a future regression here is visible rather than silent.Scope: this is wall-clock the process spent waiting, not CPU work removed. The scan's own I/O and parsing are unchanged. It's paid on every Usage-pane scan and on every forced automation rescan.
Proof of zero regression
src/main/claude-usage/,codex-usage/,opencode-usage/: 11 files, 77 tests passing.pnpm typecheckclean.Benchmark drift guards, verified by breaking them: renaming
FILE_SCAN_BATCH_SIZEthrows…is stale; reverting the scanner tosetTimeoutthrowsscanner no longer yields with setImmediate.The second guard initially did not fire — I'd written a bare
includes('setImmediate')check, which the new comment mentioningsetImmediatesatisfied even after the call reverted. Now it matches the call form (/setImmediate\(resolve\)/). A guard that a comment can satisfy is not a guard.No behaviour depends on the yield's duration: both call sites are
if (moreWork) await yieldToEventLoop()between pure in-memory batch steps.Deliberately left alone — three other
setTimeout(resolve, 0)sites exist inorca-runtime.ts:14222/14249andpty.ts:5044, and they look like the same bug but are not. They sit between PTY paste chunk writes, where the clamp acts as inter-chunk pacing, not merely a yield. Removing it there would change how fast bytes hit the terminal — a behaviour change, not a perf fix.opencode-usage/scanner.ts:148has the identical yield shape but iterates databases (2 on a real machine, ~1 yield), so it's below the bar; noted, not changed.Review loop count + verdict
2 loops. Round 1 verified the clamp claim independently and confirmed the yield frequency against the real transcript count rather than trusting the reported figure. Round 2 caught the comment-satisfiable drift guard.
Verdict: ship. One line, an in-repo sibling already proves the pattern, and the property that justifies the yield's existence measurably improves.
Made with Orca 🐋