Repository navigation
fix(claude): recheck a same-size history rewrite within one timestamp tick - #2620
Merged
Merged
Conversation
… tick On Windows, two writes a millisecond apart often keep a file's id, size, mtime and ctime (151 of 200 trials on NTFS), so a same-size rewrite of a Claude transcript kept the version its last check vouched for. The cached ends were then told as they were read, and a waiter got no new check: a rewritten notice still ended its command. The same-size-rewrite test failed 13 of 20 runs on native Windows. A check now vouches for an unchanged version without reading again only when it began at least 3 s after that version's mtime, the margin copilot-store already uses. Until then a waiter gets a check begun after it, a watcher one once the tick is past, and an answer re-reads the lines of the ends it tells.
…gain The subagent tracker lets go of its history watch in the watch's own callback, polls, then watches again. The poll's request found nobody watching and held the recheck of a version still in its timestamp tick back untimed, and the new watch never timed it, so a same-size rewrite in that tick could stay unread. A new watch now schedules what is due. The same-size-rewrite test pins its timestamp a minute ahead, so its checks all fall within the tick however slowly it runs.
|
Important Review skippedAuto incremental reviews are disabled on this repository. Please check the settings in the CodeRabbit UI or the
 |
| Layer / File(s) | Summary |
|---|---|
Timestamp-based history validation server/claude-command-history.ts |
History entries now record check start times. Recorded ends are returned directly only when the check covers the requested offset and passes the version timestamp validation. |
Recheck scheduling and regression coverage server/claude-command-history.ts, server/claude-command-history.test.ts, changelog.d/claude-history-same-size-rewrite-windows.md |
Checks that cannot yet validate a version are rescheduled, unless a waiting request requires an earlier check. Listener registration enqueues entries. Tests cover same-size rewrites and watcher scheduling; the changelog describes the Windows rewrite case. |
Estimated code review effort: 3 (Moderate) | ~20 minutes
Change: Bug fix · Severity of issue fixed: Low
Possibly related PRs
- devswha/ovis#2608: Adds the Claude command-history evidence, worker, watcher, and waiter behavior modified here.
- devswha/ovis#2616: Changes the same command-history checks and terminal-line verification extended by this timestamp-window recheck.
Suggested reviewers: duytbp
Merge Risk: 
b52f3
-
An existing false-completion case remains, but this change improves eventual detection and has no established merge-blocking regression.
Pre-merge checks: 
-
Check name Status Explanation Resolution Docstring Coverage Docstring coverage is 66.67% which is insufficient. The required threshold is 80.00%. Docstring coverage is scoped to functions touched by this diff with cyclomatic complexity of at least 2. Documenta… Write docstrings for the functions missing them to satisfy the coverage threshold. -
Check name Status Explanation Title check The title clearly identifies the main change: rechecking same-size Claude history rewrites within a timestamp tick. Description check The description includes complete Change and Validation sections. It explains the Windows filesystem issue, the implementation, regression coverage, test results, skipped checks, and the deferred Wind… Linked Issues check Check skipped because no linked issues were found for this pull request. Out of Scope Changes check Check skipped because no linked issues were found for this pull request. Full details: Description check
-
Explanation
The description includes complete Change and Validation sections. It explains the Windows filesystem issue, the implementation, regression coverage, test results, skipped checks, and the deferred Windows CI change.
-
Full details: Docstring Coverage
-
Explanation
Docstring coverage is 66.67% which is insufficient. The required threshold is 80.00%. Docstring coverage is scoped to functions touched by this diff with cyclomatic complexity of at least 2. Documentation-only edits and deletions within surviving functions are included; unchanged diff context and fully deleted functions are excluded. Analyzed 6 functions across 2 files. (1 skipped: 1 unsupported.)
Resolution
Write docstrings for the functions missing them to satisfy the coverage threshold.
-
Finishing Touches
-
Generate docstrings
-
- Commit to this branch
- Create a new PR
Generate unit tests (beta)
-
- Commit to this branch
- Create a new PR
-
- Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts
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.
A transcript whose mtime is far ahead of the clock held its recheck back until mtime + 3 s. Past setTimeout's limit (about 24.8 days), that delay fired at once and was armed again, looping every millisecond for as long as the file was watched. The recheck now comes within the check interval at the latest.
Owner
Author
|
Merge-pass review (Codex Terra xhigh, reproductions on Linux with fixed mtimes emulating the Windows collision). The fix is right about the stale end, and both new tests fail on main. Three MEDIUMs introduced by this change, so holding the merge for one round:
LOW: the new tests depend on reaching the checks within 60 s of |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
… reads again Within a version's timestamp tick, every waiter began a full check of the transcript (110 MB: five waits took 122 ms instead of 0.09 ms), and every answer re-read each end's line on its own. Past 4 MiB of end lines it told none, so while a large transcript kept being written, commands that had ended stayed running. The waiters now share one recheck once the tick is past. Until then an answer reads its ends' lines again, each run of lines close together in one read, and a line that reads otherwise starts the read over. Past 4 MiB it tells the newest ends it read, and to a request a check began after, that check vouches for them all.
…or the capped recheck Lines read at once read the bytes between them too, which the 4 MiB budget left out: short end lines 60 KB apart read 6 MB for 23 KB of lines. The budget now counts every byte read. The cap on a recheck's delay counted from now, so each time its timer fired it was put off again, and a version whose mtime is far ahead was never checked. It counts from the last check.
Owner
Author
|
Round for the merge pass's three MEDIUMs (pushed once:
Each has a test that fails on Validation at Reviews of the delta:
The test is still not in Windows CI: #2621, which waits for the owner's OK. |
Owner
Author
|
Fixes the native-Windows flake of Merge-pass review (Codex Terra xhigh, my own reproductions on Linux with fixed mtimes; the lane's omo and Terra reviews are in the PR). My three MEDIUMs from b52f318 are addressed, each with a test that fails first: future-mtime no longer loops (one capped timer); waiters share one recheck per tick (cached 110 MB, 5 waits 7 ms vs 122 ms before); a >4 MiB end set now tells the ends it could vouch for. Left as is:
#2621 adds this test file to the Windows CI job after the owner's OK. CodeRabbit's check shows skipping on this head (its earlier thread is answered and resolved); the merge pass and both reviewers reviewed it. The macOS Intel bundle job failed on a DNS error reaching crates.io, not on this change. |
This was referenced Nov 2, 2026
devswha
added a commit
that referenced
this pull request
Nov 3, 2026
#2616) ## Change This is the history-first step [requested in #2610](#2610 (comment)), cut down to the smallest move after the [review](#2616 (comment)). Only the bulk reads of `server/claude-command-history.ts` change. Everything else is main's code. - **Reverted to main exactly:** `claude-subagents.ts`, `claude-task-scan.ts`, `file-tasks.ts` and their tests. `claude-task-state.ts`, `claude-task-history.ts` and their tests are gone, along with the proof/revision/pending overlay and the task-scan retry. Also reverted: `ci.yml`, `remote-bundles.yml` and `scripts/remote-bundle-smoke.ts`. The remote bundle copies `server/` whole, so it carries the new file without them. - **Kept as on main:** the synchronous API (`historyVersion`, `sameHistory`, `commandHistory`, `evidence`, `vouchedEnds`, `waitCommandHistory` and the rest). `vouchedEnds` still rechecks known ends against a grown transcript synchronously, so an ordinary append keeps an ended command ended and #2069 holds. #2620's parts are main's code too, merged in unchanged: `evidence`'s 3 s rule and its start over on a rewritten line, `since`, the shared recheck per tick, and `vouchLines`' coalesced, budgeted re-reads. They stay synchronous on `readSync`, on the request path. - **Changed:** the drain's `scan` and `check` read through `transcriptReader` (`server/transcript-reader.ts`) instead of calling `readSync` themselves. On network filesystems and on macOS and Windows, the reader reads through the thread pool. On local Linux filesystems it still reads synchronously inside the slice (below). The drain still runs one slice at a time, with a `setImmediate` between slices, except when a slice is stuck (below). - **Local filesystems** (the round after the review of c5103d0): a call through the thread pool costs more CPU than a read the page cache answers: a wake of the pool thread, a copy on another core and a wake of the event loop. So on Linux, a transcript whose directory is on ext2/3/4, btrfs, xfs, tmpfs, zfs, f2fs or bcachefs (`statfs` type, `LOCAL`) is opened, statted, read and closed on the event loop, inside the same lease, slices and turns. - FUSE (SSHFS, virtiofs), NFS, SMB, 9p (WSL's Windows drives), overlayfs and any type not listed keep the thread pool. So do macOS and Windows. - The `statfs` itself is async, since it can block on a hung NFS mount. It is cached for 60 s per directory, and a lease that has to look it up opens the transcript at the same time, so a network filesystem pays no extra round trips before its open. - Any call on the event loop that takes over 2 ms is taken as answered by the disk, not the page cache. The rest of that lease and that transcript's leases for the next second then go through the thread pool, with the read ahead. A 1 MiB read from the page cache takes about 0.2 ms here. The open and the close on the event loop are timed the same way, and a call that throws counts as slow too. - The lookup also takes the directory's device (`stat` beside the `statfs`), and the lease's first stat compares the transcript's own device with it before any read. A transcript on another device, such as a file bind-mounted from NFS or FUSE into a local directory, goes through the thread pool, and its later leases do too for 60 s. - The reader tells the drain whether the event loop ran while the lease's last call waited (`waited()`). A slice reading on the event loop counts from the start of its step and stops at its 4 ms, as main's does; reads through the thread pool keep the rules above. - No read ahead starts while reads are on the event loop. Every byte taken in is still read between two equal stats, from `fstatSync` on the same descriptor. Cancellation and the deadline are checked before and after every call. - **Slices:** - A slice ends after 4 ms of wall time from its start, as on main, so a large session on slow storage hands over after each read. - Parsing a chunk that arrives after the slice is up through the thread pool stops 4 ms after its bytes arrive, not 4 ms after the slice started. On main the read is inside the slice. On storage where one 1 MiB read takes longer than that (SSHFS), the parse stops after a single record and the next slice reads the same chunk again from there. A chunk read on the event loop gets no such extension, since the loop had no turn while it was read. A slice on the event loop counts from the start of its step, as main's does, so its open and first stats come out of its 4 ms. - When nobody else is waiting, the session keeps its transcript open into the next slice. Opening a transcript and checking it is the path it was let in for costs several round trips on remote storage. It lets go at the end of the slice in which nobody watches or waits for the history any more, another session that can have a slice is queued, another reader waits for the reader, the read starts over, or a watcher has a new end to hear. It also lets go once half the read's 10 s deadline has passed, counted from when the read was asked for. A request for the same session does not end it. In production both readers keep it: the subagent tracker watches the history while it needs it (`watchCommandHistory`), and the task scan waits for it (`waitCommandHistory`). - A turn inside a held lease waits for two `setImmediate`s, not one. An immediate set while an I/O callback runs comes before the timers already due. With one, a slice that needs no read (the rest of a window, below) could follow the last slice before them: 44–51 event-loop stalls over 8 ms per dense read in profiling, against 0–1 with two. - **Read-ahead and reuse** (kept, re omo M1): they carry the thread-pool path that network filesystems take, which the fast path doesn't touch. Over SSHFS, without them the 276 MB sparse transcript took 9.55 s and the 95 MB dense one 9.2 s; with them, 5.1–5.6 s and 2.7–2.9 s. - A lease can start one read ahead into a second buffer, beside the operation it awaits. After a window is read, the next window, from that window's last whole line, is read while the stat after it is on its way and the window is scanned. A `window()` that asks for those bytes gets them with no second read. One that asks for other bytes lets the read ahead settle first. A lease has at most two native operations in flight, so the reader has at most four. - The check reads the next span ahead the same way, while it hashes the current one. - No read ahead starts when nobody listens, since the read then ends with that slice and a read ahead left over would hold up the lease's close. None starts when the window already reached the end, since there is nothing past it to read yet. - A slice that ends inside a window leaves that window's whole lines for the next slice. The next slice takes them in with no read and no stat, as long as no stat came since the one after they were read. On the dense transcript this cuts the reads from about three times the file to once. - Every byte taken in is still bracketed by two equal stats: a read ahead starts after a stat equal to `checked`, and reused bytes come from a read that did. A rewrite is still caught by the next stat or check. - **A stuck transcript holds up only its own history** (the review's HIGH): - A slice is taken as stuck when it has neither ended nor taken a turn for 50 ms (`STALL_MS`) while another session that can have a slice waits. The drain leaves it to end by itself and starts the next session's slice beside it. - Turns are counted per session. A held lease that takes its turns is reading, not stuck, and lets go at the end of its next turn, so healthy storage still runs one slice at a time. - At most the reader's capacity (2) of slices run at once, one per transcript. A held lease lets go only for a session that can have a slice, not for one whose transcript a stuck slice still reads. - A healthy lease's open and its checks on remote storage, several round trips, can outlast 50 ms too. The next slice then starts beside it. - **Cancel on the last release** (the review's first MEDIUM): `resetCommandHistory()` aborts the reads of every slice begun before it. The slice gives up at once, and the drain ends. What it cannot do: the native operation already started keeps its reader lease until it settles, since a syscall cannot be interrupted, and a new read of that transcript waits for that lease. `commandHistorySettled()` resolves once no slice runs and none waits to start. `commandHistorySize().draining` counts the slices left running too. - **Guards the async reads need:** - A stat is compared with the transcript as it was known when the stat was asked for. A stat older than one a status poll took in between is no news. A transcript cut short in place, even back to the size a poll saw, is read anew. - A chunk's offset, ends and checked range are published together, after the stat that follows the read. A request in between sees the read as it was. - A read that gives up on that stat (deadline or busy) keeps the chunks it already read and checked. - A session asked for again while its slice waits is queued once. - If the path names another file by the time the reader admits it, the read starts anew, as main's stat would. - Since #2620, a request that finds an end's line rewritten starts the history over (`evidence`) while a slice may be waiting for the disk. The slice drops the window or check it was reading then and reads again from the start. Without this, it took in a window read from the old position as the transcript's first bytes, until the next request or check corrected it. - **Busy reads:** a `TranscriptBusyError` (reader queue full, or a read past its 10 s deadline) backs off without using the failure budget (CodeRabbit thread on `claude-command-history.ts:98`). Other errors count as on main. - **Reader:** one shared in-process reader, for this history now and the image path later. It uses plain stats, the same form `lstatSync` gives, so its versions compare with `historyVersion`. `window()` reads into one of two 1 MiB buffers per lease, taken from a pool of the buffers of leases that ended. A buffer goes back to the pool only once every native read into it has settled, a read ahead included. The deadline timer does not keep the process alive. ## Known limits Not fixed here; each is written in the code's comments: - A local disk that stops answering inside a call on the event loop blocks the loop, as main's `readSync` does. The fallback notices a slow call only once it returns. Network filesystems can't hit this, since they never take the fast path. - A network file bind-mounted into a local directory is opened and statted once on the event loop before its device gives it away, once per 60 s for that path. The open is timed, so a slow one also sends it to the thread pool. - macOS and Windows have no fast path, so their local reads keep the thread pool's CPU cost. On macOS, `statfs` gives no fixed type for APFS; comparing the transcript directory's type with that of `/` should work, but I haven't tried it on a Mac, so it's left for a follow-up. - A native operation that never settles keeps its lease. Two of them, on two paths, keep both of the reader's leases, and every later read waits out its 10 s deadline. A read ahead counts as one. - A cancelled lease keeps its path until its operations settle. A new read of that transcript waits behind it. - Transcript identities use number stats (`dev:ino`, as `lstatSync` gives them). On a filesystem whose numbers pass 2^53, two files may share an identity. - A transcript whose reads keep running into the 10 s limit is tried again every second while it is watched, with no longer backoff. A busy reader is no failure of the transcript. ## Tests Every assertion from main's `claude-command-history.test.ts` is unchanged: against main, that file changes only its imports. At the review's request (the second MEDIUM), the assertions on lease and turn counts in tests this PR added earlier now assert outcomes: | Test | Asserted | Asserts now | |---|---|---| | keeps a transcript open across turns while no other session waits | 1 lease | each open costs 100 ms of a controlled clock, and the read took less than its reads plus two opens | | lets go of a transcript it keeps open at the end of the turn another session is asked for in | small answered at read 3; 2 leases | small answered with its end while the large one still had reads to go | | lets go of a transcript it keeps open well before the read's deadline | 2 leases | the clock moves 5 s at read 2 and 5 s more at read 4; the read still comes back complete in one wait (a lease held past half its deadline would run out of time and give up) | | gives each turn of a transcript it keeps open a slice of its own | fewer `setImmediate` calls than reads / 2 | each turn's held time on a controlled clock: at most 5 ms, and every turn but the last at least 2 ms | | reads on in the same lease when the session it reads is asked for again | 1 lease at each read | at its last read, the clock shows its reads plus exactly one open | | reads one slice for a request nobody watches or waits for | polled up to 1000 event-loop turns; 1 read, 1 lease | waits on `commandHistorySettled()`; read on some way but not through, nothing left queued, draining or timed | | reads on in one lease for a tracker's watch after it hears the first end | 2 leases | the watcher hears the first end before the read is through | | lets go of a transcript it keeps open at the end of the turn it started over in | heard before read 8 | heard while the restarted read is not through | | counts the time it keeps a transcript open from when its read was asked for | 2 leases | the clock moves 6 s before the lease opens and 5 s more at read 3; the read still comes back complete | Merging main with #2620 changed two of this PR's own tests (none of #2620's, none of main's), because of #2620's rules: - "lets go of a transcript it keeps open at the end of the turn it started over in" rewrote the first record. Under #2620 the next request's `evidence` finds that rewrite first and starts over before any slice, so the turn-break went untested. It now rewrites the record after the end's line, so only a check finds it, and its `ends` assertion is `["a"]`, not `["b"]`. Dropping `|| restarted` from the turn-break still fails it. - "keeps the chunks it read and checked when a read gives up on its stat after a chunk" now sets its file's mtime a minute back. Read within 3 s of the write, it got #2620's shared recheck, 5 more windows. No assertion changed. Every other assertion of those tests, and of every other test, is unchanged. This round also moves the tests off real time (Terra LOW): - The reader's event-loop tests run on a clock only they move (`stillClock()`), so a preempted read can't cross the 2 ms bar. 48 parallel runs of `transcript-reader.test.ts` beside 64 CPU spinners: 42 of 48 passed on 93f74fb, 48 of 48 now (also 48 of 48 with 16 spinners). - The test helpers that stand in for slow or held storage (`slowReads`, `holdWindows`) now say their reads waited off the event loop, and the one that answers at once says they didn't, so the tests behave the same whatever filesystem the host's `/tmp` is on. - "reads another transcript while one transcript's read is stuck on its disk" and "starts no more slices beside stuck ones than the reader has room for" used a real 150 ms wait. They now move a fake clock past the 50 ms stall instead. - The two reader tests that spun on `Date.now()` past a deadline now set the system time inside the callback, or while the close is pending. - "reads on by whole chunks when every read outlasts a slice" did not catch its fix: with the parse stop counted from the slice start it still passed, at c5103d0 too, because reusing a window's rest kept its read count in bounds. It now runs on a clock that moves only with the reads, and also asserts that the ends known each time the event loop runs grow by more than 100 at a time (a chunk holds about 450), not a record at a time. With the fix undone it fails. - "reads no other session beside a transcript it keeps open that takes its turns, however long it reads" no longer intercepts every 50 ms timer. The small session now asks between two turns of the large one, on a fake clock. With the old timing it passed with its fix undone, at c5103d0 too; it fails now. Each test below fails with its fix undone; I undid each fix and ran the files: | Test | Fails when | |---|---| | backs off a read the reader is too busy for… | a busy read counts as a failure | | keeps the chunks it read and checked when a read gives up on its stat… | offset and ends are published before the stat | | queues a session asked for while its slice reads only once | the requeue guard is removed | | keeps what it read when a slice's stat is older than one a poll took… | an older stat discards the read | | starts over on a transcript cut short in place while a slice reads it | a stat matching the poll's version is accepted though the transcript shrank | | reads on by whole chunks when every read outlasts a slice | the parse stop counts from the slice start | | lets a small session have its turn after each slow read of a large one | the slice counts only CPU time, or the queue is not checked | | never keeps the process alive for a read's deadline alone | the deadline timer is not unref'd | | keeps a transcript open across turns while no other session waits | each slice ends the lease | | lets go of a transcript it keeps open at the end of the turn another session is asked for in | the queue is not checked | | lets go of a transcript it keeps open at the end of the turn another reader waits for it in | the reader's waiting count is not checked | | lets go of a transcript it keeps open at the end of a turn that told a watcher of an end | a new end for a watcher is not checked, or a waiter counts as a watcher | | lets go of a transcript it keeps open well before the read's deadline | the half-deadline is not checked | | reads on in the same lease when the session it reads is asked for again | any queued session ends the lease, or each slice ends it | | gives each turn of a transcript it keeps open a slice of its own | the slice is not renewed after a turn, or there is no turn | | reads one slice for a request nobody watches or waits for | a read with no listener is kept open | | reads on in one lease for a tracker's watch after it hears the first end | a new end for a watcher does not end the lease | | lets go of a transcript it keeps open at the end of the turn it started over in | a start over does not end the lease | | counts the time it keeps a transcript open from when its read was asked for | the half-deadline counts from when the lease opened, or is not checked | | takes in the rest of a window a slice ended in without reading it again | the rest of a window is read again | | reads another transcript while one transcript's read is stuck on its disk | the drain waits for a stuck slice | | reads no other session beside a transcript it keeps open that takes its turns, however long it reads | a turn does not count as progress | | starts no more slices beside stuck ones than the reader has room for | both capacity checks are removed, the drain's and `next()`'s (either alone holds the bound) | | gives up a read stuck in flight once the last server lets go | a reset does not abort the slice's read | | reads ahead while the lease awaits a stat, and hands the bytes to the window that asks for them | the buffers are not swapped, so the next read ahead overwrites the window just returned | | lets a read ahead settle before a window that asks for other bytes | that window does not wait for the read ahead | | closes a lease and gives its buffers to another only once a read ahead nobody asked for settled | the lease does not track its read ahead | | ends a cancelled lease's read ahead without an unhandled rejection | the lease does not track its read ahead | | drops a window read across a start over that a request made while the window waited for the disk | the slice takes in a window read across a start over | | reader: reads a transcript on a local filesystem on the event loop, and one on any other through the thread pool (btrfs, ext4, tmpfs; NFS, FUSE, 9p) | every filesystem counts as local, or there is no fast path | | reader: reads through the thread pool for a second once a read on the event loop was slow, then tries the event loop again | a slow call doesn't switch the lease, or the transcript's second isn't checked | | reader: gives up a read on the event loop between windows once cancelled | the cancel checks around a sync call are removed | | reader: opens a transcript while its filesystem is looked up, and reads it on the event loop once that says local | the open waits for the lookup, or the lease stays on the thread pool after it | | reads another transcript while one on a network filesystem is stuck in its native read | every filesystem counts as local, so the stuck read blocks the event loop; or the drain waits for a stuck slice | | holds the event loop no longer than a slice and the call that ended it when it reads on the event loop | a window read on the event loop after the slice's end gets a slice of its own, or the first slice counts from when the work starts instead of from the step's start, or the reader says every call waited | | reader: reads through the thread pool for a second once an open on the event loop was slow or threw | a slow open or one that throws isn't counted, or the lease whose open was slow reads on the event loop | | reader: reads through the thread pool for a second once a close on the event loop was slow or threw | a slow close or one that throws isn't counted | | reader: reads a transcript on another device than its local directory through the thread pool | there is no device comparison, or a mismatch doesn't mark the path | | reader: reads through the thread pool for a second once a read on the event loop threw | a call that throws isn't counted | | reader: tells the work whether the event loop ran while the lease waited | a queued lease counts as not having waited, a call on the event loop doesn't clear it, or a call through the thread pool doesn't set it | Three tests have no fix to undo: - "lets the event loop run while a slice waits for the disk" checks that the drain yields while a read is held. Main's sync read cannot be held. - "starts over on a transcript rewritten and grown while it reads a window ahead" guards the read-ahead against a rewrite. Main reads no window ahead, and passes it too. - Removing the read ahead's own `.catch` does not fail "ends a cancelled lease's read ahead…": the lease's operation bookkeeping also handles that rejection. Four lines have no unit test: - The 2 ms bar's value. The tests inject slow calls far past it; where it sits between a page-cache read (about 0.2 ms per MiB) and a cold NVMe read (1.9 ms typical) is a measurement, below. - A chunk that arrives within a slice is parsed until that slice ends, not for 4 ms from its arrival. It bounds event-loop delay, and none of the tests' clocks shows a difference. Without it, event-loop p95 on SSHFS rose to 14 ms in the profiling run. - The second immediate of a turn. It orders the turn after the timers already due, which no test clock shows. Profiling measured it (see Slices). - A check pass whose check a start over cleared returns at once. Without it, the pass ends on the emptied spans and marks offset 0 checked, which the next scan's start overwrites before any end can be told, so no test can see it. It is there so check and scan treat a start over alike. One of #2620's tests sees less here: "shares one recheck within a version's tick among the requests that wait…" counts `fs.readSync`, which on this branch is only `vouchLines`; the drain reads through the reader. Its assertion holds. A probe wrapping the reader's `window()` around the same five waits found no drain reads, as on main. The inherited same-millisecond matching issue is out of scope. Possible follow-up, not in this PR: `waitCommandHistory` and `commandHistory` still call `lstatSync` through `historyVersion`, as on main. On SSHFS that holds the event loop about 100 ms per call. #2620's `vouchLines` is the same kind of read: synchronous, up to 4 MiB per call, run whenever the history is not vouched, which since #2620 includes any transcript checked within 3 s of its mtime. Moving either off the request path is a change to main's synchronous API. ## Validation - Toolchain: Bun 1.4.2, Node 22.23.4, herdr 0.9.3. The head is 7edf4df: c5103d0 (which merged main 05c9133) plus the test rework, the local-filesystem fast path, the changelog, opening during the filesystem lookup, the slice clock on the event loop, two commits strengthening one test, the reader tests' clock, and timing the open and close with the device check. The full benchmark below ran on b9b2acd; a local run on 7edf4df is after it. - `bun run check fast` on 7edf4df: 10755 passed, 0 failed, 41 skipped in 663 files; workflow syntax, generated types and themes, typecheck and build all ok. It includes #2608's tests (`claude-subagents`, `claude-task-scan`) and `file-view` and `file-pool`, which use `file-tasks.ts`. - `server/transcript-reader.test.ts` and `server/claude-command-history.test.ts`: 82 passed, 0 failed. The history tests, 8 copies at once, 3 rounds: 24 of 24 passed. - `GIT_CONFIG_COUNT=1 GIT_CONFIG_KEY_0=core.excludesFile GIT_CONFIG_VALUE_0=/dev/null bun run check run bun test server/claude-session.contract.test.ts server/api.contract.test.ts`: 207 passed, 0 failed, on an isolated herdr 0.9.3. - `git diff upstream/main -- server/claude-subagents.ts server/claude-task-scan.ts server/file-tasks.ts server/claude-subagents.test.ts server/claude-task-scan.test.ts .github scripts` is empty against 05c9133. - The review's cases ran as synthetic scripts against main and c5103d0 with the same output on both (listed in the earlier round). The review's repro, a held read of A while B is asked for, is the test "reads another transcript while one transcript's read is stuck on its disk", and its network-filesystem twin covers the stuck native read. - Measured with the same synthetic benchmark as before (gist below): b9b2acd against main 05c9133, interleaved, median [min–max]. The host also runs a VM using about 8.5 cores, so load was 9–13 and every sample is flagged; treat local differences under ~20% as noise, and CPU as the steadier figure. - Local disk, 5 runs each. Ratios are this branch over main per interleaved pair, so <1 is faster: | | main | this branch | ratio | |---|---|---|---| | 276 MB sparse, page cache warm | 65 ms [57–70] | 74 ms [66–79] | 1.15 [0.96–1.34] | | 276 MB sparse, cold | 158 ms [154–189] | 164 ms [146–203] | 1.02 [0.85–1.28] | | 95 MB dense, warm | 1027 ms [961–1166] | 949 ms [915–1124] | 0.94 [0.89–0.96] | | 95 MB dense, cold | 854 ms [759–994] | 819 ms [735–854] | 0.93 [0.86–1.03] | | CPU (user + sys), sparse warm | 64 ms | 90 ms | 1.25 [1.06–1.40] | | CPU, sparse cold / dense warm | 157 / 1172 ms | 190 / 1104 ms | 1.22 / 0.96 | | longest event-loop gap, sparse warm / dense warm | 4.7 / 7.3 ms | 4.7 / 7.3 ms | | | other requests during the sparse read, p95 | 4.1 ms | 4.1 ms | | | 1 MB session, warm / cold | 5 / 5 ms | 8 / 7 ms | 1.60 / 1.63 | Sparse warm CPU is the figure the last review blocked on: 78 ms on main against 165 on c5103d0 in your run. Three full runs across this round's commits on this host put it at 1.16, 1.10 and 1.25 times main's (fd22a07, b994f29, b9b2acd), against 1.48 for c5103d0 in the same harness here. The branch's own sparse warm CPU held at 77–93 ms across those runs; main's moved between 64 and 88, which is most of the spread in the ratio. What remains is mostly JIT time for the extra code paths: in a profile of the second read in one process, main-thread work matched main's within 2 ms, and the pool threads did none. Sparse warm read time overlaps main's in every run (1.02–1.15). Cold sparse costs ~20% more CPU than main: on a cold read the first slow call (over 2 ms) moves the rest of the lease to the thread pool, which is what keeps a local disk that stalls from blocking the event loop for more than one call. The longest event-loop gap now matches main's. On the fast path, slices take only what fits in their 4 ms, as main's do. Loop-gap max for the 1 MB session reads 4.6–4.8 ms against main's ~1 ms, but that is how the harness samples, not a longer block. The sampler records a gap only when its 2 ms tick fires before the read resolves, so a read that ends on sync work never has its last gap counted. Main's small read usually ends inside its first gap. One main run that got a second tick recorded 5.4 ms. A probe that also counts the last gap found the longest block at 4.3–5.1 ms on main and 3.3–5.4 ms here: parsing the 1 MiB window inside one slice. - Local disk on 7edf4df against main 05c9133, 5 runs each: sparse warm 61 → 67 ms (ratio 1.15 [1.04–1.62]), CPU ratio 1.22 [1.13–1.68]; dense warm 0.95, dense cold 0.86; longest event-loop gap, sparse warm 4.6 / 4.7 ms and dense warm 6.6 / 6.4 ms. Sparse cold CPU came out 1.39 [1.07–1.76] in this run (1.22 on b9b2acd); a cache miss now also stats the directory beside its `statfs`, and every bench read is a fresh process, so each pays it once. I haven't separated that from load; your spot-check on a quiet host will show it better. - Over SSHFS: sshfs 3.7.6 with `cache=no,direct_io,no_readahead`, 14 ms round trip, 3 runs each. These are unchanged from c5103d0; network filesystems never take the fast path. An interleaved SSHFS run of c5103d0 against b9b2acd's parent gave ratios of 1.00 and 1.02 for the small-session rows. | | main | this branch | |---|---|---| | 276 MB sparse, total | 61.6 s [61.5–61.7] | 5.18 s [5.14–5.20] | | other requests during it, p95 / max | 155 / 275–345 ms | 1.0–1.8 / 101–103 ms | | longest event-loop stall | 177–247 ms | 101–102 ms | | 95 MB dense, total | not done after 300 s, 3 of 3 (1.0 MB read) | 2.58 s [2.54–2.71] | | other requests during it, p95 / max | 153 / 274–276 ms | 33–42 / 100–102 ms | | 1 MB session alone | 7.75 s | 0.49 s | | 1 MB session while the 276 MB one reads | 15.3 s | 0.47 s | | 1 MB session while the 95 MB one reads | 15.4 s | 0.48 s | | CPU, sparse (user + sys) | 0.36 s | 0.31 s | Main sets the slice's 4 ms clock before its blocking read, and one 1 MiB read over SSHFS takes ~110 ms, so each slice parses about one record and the next slice reads the same chunk again. This branch's single ~100 ms stall per read fits one round trip of the synchronous `lstatSync` in `historyVersion` (see the follow-up). - System calls on the transcript, page cache warm, under strace: | | main | this branch | |---|---|---| | dense: reads / MiB read / opens | 668 / 422.7 / 341 | 91 / 90.6 / 2 | | sparse: reads / fstats / opens | 286 / 573 / 35 | 282 / 283 / 2 | Main with #2620 reads the dense transcript about 4.6 times over; this branch reads it once. - A small session's extra ~3 ms is once per process: starting Bun's thread pool for the first `statfs` and open of a directory, and the first run of the reader's code paths. After that, on a local filesystem, a read makes no thread-pool round trip, and compiled it is within noise of main's (2.3 against 2.1 ms in the profile). - Not run locally: the integration and browser suites, SSH, native Windows and macOS. Upstream CI covers them. - The benchmark is a standalone harness anyone can run: https://gist.github.com/duytbp/470e90421331b31ccd953de200d6aae0 (synthetic transcripts only; `bench.sh <rev>` for local, `MODES=sshfs` adds the SSHFS lab, which needs Linux and sudo). - Optional follow-up for the owner: adding `server/transcript-reader.test.ts` and `server/claude-command-history.test.ts` to the Native Windows and remote Windows test lists. That is a workflow change, so it is left out until approved. All fixtures are synthetic files in temporary directories. No live herdr session or real transcript was used. --------- Co-authored-by: devswha <devswha@gmail.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Change
On native Windows,
server/claude-command-history.test.ts"invalidates completion authority on replacement, truncation and same-size rewrites" failed 13 of 20 runs on main (38230517), attest.ts:56: expected["alt"], received["new"].This is a product bug, not test timing. On NTFS, two writes about a millisecond apart often keep the file's id, size, mtime and ctime (a probe on winvm: 151 of 200 same-size rewrites kept all of them, e.g.
ino 3659174697466272,size 234,mtimeNs 1793646403734723000before and after). The history cache keys a version ondev:ino, size and mtime, so once a check had vouched for a version,due()never read it again andevidence()told the cached ends. A notice rewritten in place could keep ending a command it no longer ends, and a waiter got no new check. A Linux filesystem with coarse timestamps has the same exposure.copilot-store.tsalready uses,LOG_TIMESTAMP_MARGIN_NS). Until then a waiter gets a check begun after it, a watcher gets one once the tick is past, and an answer re-reads the lines of the ends it tells (vouchedEnds).Not in Windows CI yet: no Windows job runs this test file. Adding it to the
windows-installlist is a workflow change, so it goes in a separate PR that waits for the owner's OK.Validation
%TEMP%clone,bun test ./server/claude-command-history.test.ts20 times: main3823051713/20 fail, this branchfb6b49970/20 fail, headc16d0c9e0/20 fail.bun testof claude-command-history, claude-subagents and claude-task-scan: 148 pass, 0 fail.bun run check fastonc16d0c9e: unit 10,692 pass, 0 fail, 41 skip; workflow syntax, generated files, typecheck and build ok.c16d0c9ewith a test. P3 (the test assumed a 3 s budget) fixed: its mtime is set 60 s ahead. P2 declined: past 4 MiB of end lines, an answer within the 3 s tick tells no ends until the file is quiet. That matches the existing behaviour for a grown version and errs toward "running", never toward a false "finished". An omo code review is still running and its result will be added as a comment.check full.