Skip to content

perf(feed-debug): pace persistence appends by time instead of per runtimes replacement - #750

Open
Juliusolsson05 wants to merge 5 commits into
mainfrom
perf/feed-debug-persist-batching
Open

perf(feed-debug): pace persistence appends by time instead of per runtimes replacement#750
Juliusolsson05 wants to merge 5 commits into
mainfrom
perf/feed-debug-persist-batching

Conversation

@Juliusolsson05

@Juliusolsson05 Juliusolsson05 commented Sep 3, 2026

Copy link
Copy Markdown
Owner

Problem

useFeedDebugPersist runs in a useEffect keyed on the runtimes map, which is replaced dozens of times per second while a turn streams. Every replacement that found new feed-debug entries sent them to main immediately and the success path re-drained at once, so the append cadence followed the streaming cadence. Perf journal evidence (#748): 8,649–10,159 debug:append-feed-log invokes in a 77-minute run (111/min average, 20/s in bursts); 44 calls ≥ 50 ms, max 206 ms; on the Sep 1 run p50 87 ms, p95 352 ms, max 1,159 ms. Each invoke is a writeFile(flag:'a') and a retention-prune schedule on the main thread.

Behaviour

  • A pure policy (feedDebugFlushPolicy.ts, decideFeedDebugFlush) decides when a session's pending entries go out: the first batch after a quiet period flushes immediately; anything that arrives within FEED_DEBUG_FLUSH_INTERVAL_MS (1.5 s) of the last attempt waits for one per-session timer; FEED_DEBUG_FLUSH_MAX_PENDING (256 entries) or FEED_DEBUG_FLUSH_MAX_PENDING_BYTES (1 MiB, from the ring's cached per-entry estimate) forces an immediate flush.
  • The persisted / in-flight cursors and the one-append-in-flight rule are untouched, so retry-on-failure and idempotence by (sessionId, id) on the main side still hold.
  • A rejected append counts as an attempt: entries stay pending (the persisted cursor only advances on success) and the policy re-runs so an idle session retries after the interval instead of waiting for another replacement or following every streamed delta.
  • A session that leaves runtimes (replacement, pane close, tab kill, hard reload — soft reload replaces the runtime under the same key and does not fire the removal flush; its pending entries ride the armed timer into the next epoch, tracked in bug(feed-debug): soft reload restarts entry ids below the persisted cursor so persistence silently stops #770) gets one final, unpaced flush of its trailing entries from its last snapshot — parked until an in-flight append resolves if there is one — then its timers/cursors are dropped. Those entries (exit code, kill reason) are what debug bundles read for closed panes.
  • Pending-count is computed by scanning from the tail (O(pending), not O(ring)), since the hook runs per replacement.
  • Timers live in a ref and are cleared on unmount only; the per-replacement effect must not tear them down or the interval would never elapse under load.

Design decisions

  • Time is the primary pacing because the goal is fewer main-thread writes; the count ceiling bounds batch size, and the byte ceiling exists because the ring is byte-capped at 4 MiB and evicts from the head — with the perf(renderer): feed-debug ring is count-capped only and reached 130 MiB in one session #722 shape (hundreds of KB per entry) twenty entries already exceed the ring, so waiting for 256 would let unpersisted entries be evicted. A quarter of the ring forces the flush long before that.
  • Immediate first flush keeps "Save Debug Logs" right after a bad paint truthful: the entry that explains it is on disk within one round trip, not up to 1.5 s later.
  • No pagehide flush: an invoke cannot be awaited past teardown, so up to 1.5 s of feed-debug can be lost at window close or on a hard renderer crash. Session removal is NOT in that category — it flushes synchronously with the removal (see Behaviour).

Linked issues

Fixes #748. Refs #722, #103.

Verification

  • feedDebugFlushPolicy.test.ts (6): immediate on first batch and after the interval; timer for the remainder inside it; forced at the count ceiling; forced at the byte ceiling before the count is reached; nothing while in flight or with nothing pending; tail-scan pending count.
  • useFeedDebugPersist.renderer.test.tsx (8, fake timers, stubbed window.api.appendFeedDebugLog): 20 replacements inside the interval produce one immediate append and exactly one paced append carrying all 20 entries in order; entries arriving while an append is in flight are paced on resolve (not drained); the count ceiling forces a flush inside the interval; three ~512 KB entries force a flush via the byte ceiling; a removed session's trailing entries are flushed at once, and once its in-flight append resolves; a rejected append keeps entries pending and retries no sooner than the interval with the full range; unmount clears the timer.
  • --project renderer src/renderer/src/workspace/hook/persistence/ — 22 passed; --project unit persistence + feedDebug.test.ts — 13 passed; npx tsc -b — clean.

Limitations / follow-ups

🤖 Generated with Claude Code

https://claude.ai/code/session_01Kk16MNVJtWAnCeGxGRuHqa

Juliusolsson05 and others added 3 commits September 3, 2026 13:53
Refs #748

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Kk16MNVJtWAnCeGxGRuHqa
…times replacement

The persistence hook flushed pending feed-debug entries on every runtimes
replacement and re-drained immediately on success, so the append cadence
followed the streaming cadence: 8,649–10,159 debug:append-feed-log invokes
in a 77-minute run, 20/s in bursts, each a writeFile(flag:'a') plus a
retention-prune schedule on the main thread (p95 352 ms, max 1.2 s).

A pure policy now decides when to flush: the first batch after a quiet
period goes out at once so the entry explaining a bad paint is on disk
quickly, anything within 1.5 s of the last attempt rides one per-session
timer, and a 256-entry ceiling forces a flush so a burst cannot pile up an
outsized batch. The persisted/in-flight cursors and the one-append-in-
flight rule are unchanged; a failed attempt counts as an attempt so a
rejecting main does not turn streaming into a retry storm.

Fixes #748
Refs #722

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Kk16MNVJtWAnCeGxGRuHqa
…ling

The ring is byte-capped at 4 MiB and evicts from the head, so an entry
waiting on the pacing timer can be evicted before it is persisted. A
count ceiling does not bound that: the #722 shape is a few hundred KB per
visible_rows entry, where twenty entries already exceed the ring. A byte
ceiling at a quarter of the ring, computed from the ring's own cached
per-entry estimate, forces the flush long before eviction can reach
unpersisted entries.

Refs #748, #722

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Kk16MNVJtWAnCeGxGRuHqa
…f losing them to the timer

Review of #750: a session leaves runtimes on replacement, pane close, tab
kill and reload, and its last entries — the exit code, the kill reason —
are written in the final second. With pacing alone they sat on a timer
that found no runtime when it fired; the pre-pacing hook shipped them from
the same effect pass that appended them. Removed sessions now get one
final, unpaced flush from their last runtime snapshot (parked until an
in-flight append resolves), then their bookkeeping is dropped. A failed
append also re-runs the policy so an idle session retries after the
interval, and post-unmount resolutions no longer re-arm timers.

Comments that still described per-tick shipping are corrected; the plan
records the byte ceiling and the removal flush.

Refs #748, #770, #771

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Kk16MNVJtWAnCeGxGRuHqa
@Juliusolsson05

Copy link
Copy Markdown
Owner Author

Review applied in 6a6f84a:

@Juliusolsson05 Juliusolsson05 left a comment

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adversarial review (re-run after the pause; worktree 6a6f84a, all commands run locally).

VERDICT: REQUEST-CHANGES

Core pacing design is sound — pure policy, one timer/session, one-in-flight preserved, cursors untouched — but the rework commit introduced the issues below.

  1. BLOCKER — Removed-session final flush has no pacing: persistent rejection spins an unbounded retry loop. useFeedDebugPersist.ts:157-163 — the final path calls send() whenever remaining > 0 without consulting lastAttemptAtRef or decideFeedDebugFlush. On rejection, .catch (line 137) re-invokes consider(sessionId, undefined) → session is gone from latestRuntimesReffinal path again → send() again. No interval, ceiling, or attempt cap — a tight loop for as long as main keeps rejecting (disk full/EACCES/EIO at close time, shape validation, or #771's fail-closed branch after its own fix). This reintroduces exactly the retry storm the PR exists to kill, and contradicts the PR body claim "A rejected append counts as an attempt … retries after the interval" (true only for live sessions). Fix: apply the interval to the final path too. No test covers rejection on a removed session.
  2. SHOULD-FIX — unmountedRef never reset on (re)mount; permanently true after StrictMode's dev double-mount. useFeedDebugPersist.ts:73-77 sets the flag in cleanup but the effect body never sets it back to false. App runs under <React.StrictMode> (main.tsx:79); after the simulated unmount/remount every .then/.catch bails — resolve-path pacing and failure retry are dead in dev. One-line fix: unmountedRef.current = false in the mount-effect body. New tests render without StrictMode so they cannot catch this.
  3. SHOULD-FIX — Soft reload bypasses the removal flush; up to 1.5 s of trailing entries is a new loss window. The removal flush only fires when a session key leaves the map (useFeedDebugPersist.ts:202-208). softReloadAgentView/softReloadRuntime replaces the runtime under the same key (session.ts:120-192; reset = emptyRuntime() at :142 restarts feedDebugNextId), so no final flush fires: pending entries on the armed timer are silently dropped, and #770 keeps the new epoch off disk. Hard paths (replaceSession, reloadAgentSessions, killSession) do remove the key and are covered — the PR body's blanket claim is wrong for soft reload. Fix: detect the epoch reset (incoming feedDebugNextId below the previous pass's) and final-flush the previous runtime; at minimum correct the body and document the window.
  4. NIT — forget() doesn't clear the session's feed-debug cursors in WorkspaceRefs (useFeedDebugPersist.ts:141-149); entries leak for the app lifetime.
  5. NIT — per-replacement allocation at useFeedDebugPersist.ts:175: slice(-pendingCount) feeds the byte estimator dozens of times/second/session; an index-based tail sum avoids it.
  6. NIT — tests: install param shadows the imported appendFeedDebugLog; missing coverage for findings 1-3.

Verified non-issues: byte ceiling at ¼ of the ring correctly bounds eviction risk while not in flight; countPendingFeedDebug tail scan consistent with selectFeedDebugAppendBatch under monotone ids including the #770 restart shape; armed-timer-at-removal race resolves benignly; #770/#771 behaviors unchanged (correctly separate).

Commands: renderer persistence suite 22/22 PASS; unit persistence+feedDebug 13/13 PASS; npm run typecheck PASS.

…unts

The removal path's rejection handler re-enters the final branch with the
session gone, so an unpaced final flush retried once per microtask for as
long as main kept rejecting — the retry storm this PR exists to kill,
resurrected on the removal path. The first final flush stays immediate
(removal is one append, and delaying it would drop exactly the exit-code
entries it exists to persist); only retries the final branch itself made
inside the interval wait, on a dedicated per-session attempt stamp the
live cadence cannot contaminate.

The unmount-only effect also re-arms its flag in the effect body: React
18 StrictMode's simulated unmount left it permanently true, deadening
every later resolve/reject callback in dev.

Addressses the blocker and StrictMode finding from the round-2 review.
@Juliusolsson05

Copy link
Copy Markdown
Owner Author

Round-3 rework pushed (f622997):

  • Blocker 1 (final-flush retry storm) — fixed. The final branch now keeps its own per-session attempt stamp (finalAttemptAtRef): the first final flush stays immediate (delaying it would drop exactly the exit-code entries the branch exists to persist; the live cadence's stamp can't be reused because the pre-removal batch is typically milliseconds old), while any retry the final branch itself made inside the interval arms the shared per-session timer instead of re-sending. forget() clears the stamp. Regression test drives two consecutive rejections and asserts exactly one attempt per interval and a clean stop after success.
  • Should-fix 2 (StrictMode unmountedRef) — fixed. The unmount-only effect re-arms its flag in the effect body; new test renders under <StrictMode> and asserts the durable cursor still advances after the simulated remount.
  • Should-fix 3 (soft-reload loss window) — not in this PR. It is entangled with the epoch-restart behavior tracked separately in bug(feed-debug): soft reload restarts entry ids below the persisted cursor so persistence silently stops #770; the PR body claim about soft reload has been corrected below.

Verification: renderer persistence suite 10/10 (incl. 2 new), unit persistence + feedDebug 13/13, npm run typecheck clean.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

perf(feed-debug): persistence appends on every runtimes replacement instead of batching by time

1 participant