Codex re-pin: get the rollout walk off the event loop - #45
Open
thomwolf wants to merge 2 commits into
Open
Conversation
On the Space, DATA_DIR / HOME / CLAUDE_CONFIG_DIR are on the FUSE bucket, where a statSync costs ~85ms against 0.01ms on local disk (98% of stats there exceed 50ms). Node runs JS on one thread, so a single such call freezes every pane the server is carrying for that long. This has now bitten us three times: claudeTranscriptsSince, and then codexRolloutsSince, which is still sync and walks $CODEX_HOME/sessions — a symlink onto the bucket — on the repin beat. It is hard to spot because nothing in the stack reports it. In particular the kernel's pressure accounting cannot: FUSE parks the caller in wait_event_interruptible (state S), not io_schedule, so the wait is never counted as iowait and /proc/pressure/io reads 0.00 while the loop is stuck. Finding the last one needed a wchan sample of the main thread. So leave a tripwire. Any sync fs call over AM_SLOWFS_MS (default 50) logs the path and the caller's own source line, which is the part that turns "something is slow" into a diff. Silent on a normal filesystem, where nothing approaches the threshold, and AM_SLOWFS_MS=0 disables it. Overhead when nothing is slow is two performance.now() calls against a ~10us syscall; a stack is captured only for a call that already blocked. Rate-limited to one line per call site per 10s so a stalled mount cannot become a log storm, and the wrapper neither throws from its own logging nor swallows the call's errors — it sits in front of every sync fs call in the process, including ones inside catch blocks. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
thomwolf
force-pushed
the
perf/slow-fs-probe
branch
from
August 7, 2026 12:39
a78bc81 to
a8abb3d
Compare
The Space freezes for 400-750ms, several times a minute. It is this: the codex re-pin watcher walks $CODEX_HOME/sessions synchronously — a readdirSync per day-directory plus a statSync per rollout, then a readSync of up to a megabyte of the winner — on the REPIN_MS beat, once per codex session. CODEX_HOME is on local disk, which is why this looked safe. Its `sessions` child is not: it is a symlink onto the FUSE bucket. `stat -f` reports fuseblk, and a stat there costs ~85ms against 0.01ms locally. `find` on that path reports it empty, because find does not follow a symlink given as its starting point without -L — which is how it stayed hidden. Measured on the live Space before this change: event-loop stalls over 250ms at 2.5/minute, worst 3.9s, with stall-to-stall intervals of 20.4-20.9s — REPIN_MS, to within sampling error. During those stalls the process burns LESS cpu than when healthy (0% on-CPU vs 10.8%) and read syscalls fall from 1434/s to 18/s: it is asleep in the bucket, not busy. /proc/1/task/1/wchan puts the main thread in FUSE's request_wait_answer 3.67% of wall time. So make it async, exactly as claudeTranscriptsSince already is, and sequential for the same reason — parallel FUSE stats would saturate the 4-thread libuv pool and push every other fs operation in the process behind them. Awaiting brings the hazards PR #35 fixed for the claude watcher, so it takes the same three remedies: - one rearm per tick, from a single place, so a tick that throws neither kills the watcher nor arms two timers; - a host-identity guard, so a relaunch landing mid-walk cannot leave two chains beating with only one reachable by clearTimeout; - claims and pins re-read after the awaits rather than snapshotted before them, so a rollout claimed while we walked is not stolen from its owner. The stale-pin check moves off the launch path into the first beat, since it too reads the bucket. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.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.
Fixes the multi-second freezes in the Space, and leaves a tripwire so this class
of bug cannot hide again.
The bug
The codex re-pin watcher walks
$CODEX_HOME/sessionssynchronously — areaddirSyncper day-directory plus astatSyncper rollout, then areadSyncof up to a megabyte of the winner — on the
REPIN_MSbeat, once per codexsession. Node runs JS on one thread, so that is a freeze of every pane the
server is carrying.
CODEX_HOMEis on local disk, which is why this looked safe. Itssessionschild is not: it is a symlink onto the FUSE bucket, where a stat costs ~85ms
against 0.01ms locally (98% of stats there exceed 50ms).
It stayed hidden because both the obvious checks lie about it.
findon thatpath reports the directory empty — it does not follow a symlink given as its
starting point without
-L. And the kernel's pressure accounting reads zero:FUSE parks the caller in
wait_event_interruptible(state S, never D), notio_schedule, so the wait is never counted as iowait and/proc/pressure/ioshows
0.00while the loop is stuck.Evidence
Measured on the live Space, on loopback with no network in the path:
20.461, 20.686, 20.935s —
REPIN_MS, to within sampling error10.8%) and read syscalls fall from 1434/s to 18/s — asleep, not busy
/proc/1/task/1/wchanputs the main thread in FUSE'srequest_wait_answer3.67% of wall time (async fs would sit on the libuvthreadpool instead)
is not a leak
The fix
Make the walk and the head-read async, exactly as
claudeTranscriptsSincealready is, and sequential for the same stated reason — parallel FUSE stats
would saturate the 4-thread libuv pool and push every other fs operation in the
process behind them.
Awaiting reintroduces the hazards #35 fixed for the claude watcher, so it takes
the same three remedies:
kills the watcher nor arms two timers;
chains beating with only one reachable by
clearTimeout;them, so a rollout claimed while we walked is not stolen from its owner.
The stale-pin check moves off the launch path into the first beat, since it
reads the bucket too.
The tripwire (second commit)
Any sync
fscall overAM_SLOWFS_MS(default 50) logs the path and thecaller's own source line. This bug class has now hit three times —
claudeTranscriptsSince,codexRolloutsSince— and nothing in the stackreports it, as above. Silent on a normal filesystem;
AM_SLOWFS_MS=0disablesit; rate-limited to one line per call site per 10s; the wrapper never throws
from its own logging and never swallows the call's errors.
Tests
server/test/codex-repin.test.mjs(10): walks the realYYYY/MM/DDlayout,newest-first ordering,
sinceMsfiltering, ignores non-rollouts, respects thedepth cap, tolerates an absent root, and asserts the function is actually async.
server/test/slowfs.test.mjs(17): behaviour, error propagation andrealpathSync.nativeunchanged; attribution points at the caller; repeatscollapse to one line.
Full suite passes: repin 30, opencode-resume 16, terminal-modes, trace-tail, and
both boot suites (
migration,resize).Verified on a separate test Space
thomwolf/am-perftest, private, with its own bucket mounted at/data(never the live one — two Spaces writing the same
sessions.jsonwould corruptit).
stat -finside confirmsfuseblk. Seeded with 10 rollouts across 3day-dirs, mirroring the live layout. Both implementations run verbatim against
that tree while a 20ms heartbeat records its own drift, which is event-loop
block time.
Order is the whole experiment: the FUSE attribute cache is cold only for
whichever phase runs first, and cold is ~1s against ~2ms warm — so
sync-first/async-second would flatter this PR for free. Run in the hostile
order, handing the cold cache to the new code:
Same mount, same tree, same cold cache. The new version does the full ~819ms of
I/O and blocks the loop for 1ms — 0.1%, against sync's 98%. Warm walks are
1-2ms either way, which is exactly why the live stalls are intermittent: they
are cold-cache events. Control: on tmpfs both versions are identical (1ms), so
the harness does not manufacture a difference.
The fixed build then deployed and ran clean there (
/api/healthok, no[codex] repin tick failed).Not covered: the fixed build's effect on the live 20s beat end-to-end — the
test Space has no codex sessions and starting real ones needs codex auth. The
walk A/B proves the mechanism; the end-to-end stall rate is unmeasured.
The tripwire paid for itself on the first boot
It named ten more sync-FUSE call sites, with file:line — about 3s of blocked
startup, all boot-path (so not the recurring stall, but the same bug class):
loadAmConfiglogged twice, so it may sit on a warm path too. Follow-up, notthis PR.
🤖 Generated with Claude Code