fix(tui): prevent large session render loops - #424
Conversation
4cbfff3 to
86eb1e7
Compare
code-yeongyu
left a comment
There was a problem hiding this comment.
Ultradebate review (5-persona adversarial panel: architect / pragmatist / nitpicker / creative-skeptic / deep-logic)
Two debate rounds converged unanimously (5:0) on REQUEST-CHANGES. The core CPU fix is right and stays: deferring the over-wide crashData construction behind strictRender || !overWideCrashDumpWritten (tui.ts) genuinely kills the per-frame visibleWidth() transcript scan, and the GoalElapsedTicker label memoization is sound. changes.md discipline is exemplary. But three verified defects must be fixed before merge.
Blocking
F2 — the Working elapsed counter freezes for up to 60s while output streams (worst defect, lead-verified). The elapsed label (7m 07s • esc to interrupt) is recomputed only inside Loader.updateDisplay(), which runs exclusively on the message interval timer (packages/tui/src/components/loader.ts). External event-driven requestRender() calls repaint the cached string. With messageIntervalMs at 60_000 in >=1000-entry sessions, users watching tokens stream see a motionless timer — indistinguishable from a hang, inviting esc-interrupts of healthy runs. The changes.md claim "the long fallback preserves elapsed status" is falsified by this path. Fix: large-session message cadence 60_000 -> 1_000 ms. That still cuts message renders 32x; the perf claim survives intact.
F1 — startToolHookStatusTimer escapes the policy (flagged independently by all 5 reviewers). interactive-mode.ts:2199-2206 still hard-codes the raw 32 ms DEFAULT_WORKING_STATUS_MESSAGE_ANIMATION_INTERVAL_MS, and refreshToolHookStatuses calls this.ui.requestRender() every tick. While any tool hook is active, a large session repaints the full tree at ~31 fps — exactly the pathology this PR exists to kill, driven by the very constant the PR repurposed. Fix: route it through largeSessionWorkingStatusInterval (one line).
F4 — GoalElapsedTicker.sync() breaks its own documented contract. The docstring promises "render once immediately," but sync() routes through the now-memoized tick() (elapsed-ticker.ts:78-84). stop() clears the memo; an active-to-active resync does not, so a goal switch whose label formats identically (e.g. two goals both at 1h) silently drops the promised render. Fix: clear lastRenderedElapsedLabel in sync() before tick() (one line).
Follow-up (document, don't block)
F3 — threshold sampling. sessionEntryCount is read once per indicator creation; a session crossing 1000 entries mid-turn keeps the fast cadence until the next turn, and any extension passing custom setWorkingIndicator() options bypasses the throttle entirely (?? fallback branch). Acceptable pragmatism, but the semantics deserve a sentence in changes.md.
Nits
F5 — render-contract.test.ts:231 asserts the first over-wide frame scans exactly 1 line, hard-coding the harness's single-line component; assert > before for the first frame and keep exact equality only on the second (the real regression guard). Also sessionEntryCount (interactive-mode.ts:2370) is computed even when this.workingIndicatorOptions short-circuits the ?? — hoist into the fallback branch.
Required before merge
LARGE_SESSION_WORKING_STATUS_INTERVAL_MSfor the message cadence: 60_000 -> 1_000 (decorative indicator may stay slow)- Hook-status timer through
largeSessionWorkingStatusInterval - Memo reset in
sync() - changes.md wording fix ("preserves elapsed status")
- Behavioral tests locking F1/F2/F4
| const WORKING_STATUS_MESSAGE_SHIMMER_SWEEP_MS = 2_000; | ||
| const ACTIVE_TOOL_WORKING_LABEL_MAX_LENGTH = 80; | ||
| const LARGE_SESSION_ENTRY_THRESHOLD = 1000; | ||
| const LARGE_SESSION_WORKING_STATUS_INTERVAL_MS = 60_000; |
There was a problem hiding this comment.
F2 (blocking): 60_000 ms as the message cadence freezes the elapsed label. Loader.updateDisplay() is the only place the (7m 07s ...) text is recomputed, and it runs only on this interval — event-driven requestRender() repaints the cached string. In a >=1000-entry session the timer visibly stops for up to a minute while tokens stream, which reads as a hang. Use 1_000 for the message interval (still a 32x reduction). The decorative indicator frame cadence may stay slow.
Also worth a provenance comment: neither 1000 entries nor the interval constant is tied to a measurement; the PR's own motivating case is byte-size-driven (34 MB), not entry-count-driven.
| } | ||
|
|
||
| private getWorkingIndicatorOptions(): LoaderIndicatorOptions { | ||
| const sessionEntryCount = this.sessionManager.getEntries().length; |
There was a problem hiding this comment.
F1 (blocking, adjacent): startToolHookStatusTimer (line ~2199, outside this hunk) still uses the raw 32 ms DEFAULT_WORKING_STATUS_MESSAGE_ANIMATION_INTERVAL_MS and requestRender()s every tick — during active tool hooks a large session still repaints at ~31 fps, the exact loop this PR kills elsewhere. Route it through largeSessionWorkingStatusInterval too.
F5 (nit): this sessionEntryCount read is dead work whenever this.workingIndicatorOptions is set (the whole ?? right side is discarded). Cheap since getEntries() is mutation-memoized, but hoist it into the fallback branch.
F3 (follow-up): the count is sampled once per indicator creation — a mid-turn crossing of 1000 keeps the fast cadence until the next turn, and custom setWorkingIndicator() options bypass the throttle entirely. Document both semantics in changes.md.
| this.render(this.ctx, this.goal, goalLiveElapsedSeconds(this.goal, this.measuredFromMilliseconds, this.now())); | ||
| const liveElapsedSeconds = goalLiveElapsedSeconds(this.goal, this.measuredFromMilliseconds, this.now()); | ||
| const elapsedLabel = formatGoalElapsedSeconds(liveElapsedSeconds); | ||
| if (elapsedLabel === this.lastRenderedElapsedLabel) return; |
There was a problem hiding this comment.
F4 (blocking): sync()'s docstring promises "render once immediately," but it routes through this memoized early-return. stop() clears lastRenderedElapsedLabel; an active-to-active sync() does not — switching goals whose labels format identically (two goals both at 1h) silently skips the promised render. Clear the memo in sync() before calling tick().
| const scansAfterFirstOverWideFrame = renderDiagnosticStats().linesScanned; | ||
| const crashLogPath = path.join(home, ".senpi", "agent", "senpi-crash.log"); | ||
| assert.ok(fs.existsSync(crashLogPath)); | ||
| assert.strictEqual(scansAfterFirstOverWideFrame - scansBeforeOverWideFrame, 1); |
There was a problem hiding this comment.
F5 (nit): this asserts the first over-wide frame scanned exactly 1 line, which hard-codes the harness component rendering a single line (renderDiagnosticLineScans += lines.length). Any wrapper line added to the harness breaks this for an irrelevant reason. Assert > scansBeforeOverWideFrame here; keep the exact-equality assertion on the second frame below — that one is the actual regression guard.
Address review findings on the large-session render throttling: - keep the Working elapsed label honest with a 1s large-session message cadence while the decorative indicator falls back to 60s - route the tool-hook status timer through the same large-session policy - clear the goal elapsed-label memo in sync() so its documented immediate render always fires across goal switches - return custom working indicator options before sampling session entries - relax the first over-wide diagnostic scan assertion to survive harness changes; document threshold sampling and custom-indicator bypass
code-yeongyu
left a comment
There was a problem hiding this comment.
Re-review after 2f1a636 — all requested changes verified
- F2 fixed: large-session cadence split — informational Working message and hook rows at 1_000 ms, decorative indicator fallback at 60_000 ms (
working-status.tsper-use interval parameter;interactive-mode.tsconstants). The elapsed label stays honest at 1 fps while retaining the 32x render reduction. - F1 fixed:
startToolHookStatusTimernow routes throughlargeSessionWorkingStatusInterval; locked bytest/hook-status-ticker.test.ts(32 ms small / 1_000 ms large). - F4 fixed:
sync()clearslastRenderedElapsedLabelbefore its promised immediate render; goal-switch-same-label test added. - F5 fixed: first-frame scan assertion relaxed to
> 0(second-frame exact equality kept as the regression guard); deadsessionEntryCountread hoisted behind the custom-options early return. - F3 documented: threshold sampling at indicator/ticker creation and the intentional custom
setWorkingIndicator()bypass are now stated inchanges.md.
Verification (lead-run): coding-agent focused tests 22/22, tui package tests exit 0 (render-contract 7/7), root npm run check exit 0, senpi-qa post-fix evidence mock-loop 42/42 · cli-smoke 8/8 · tui-smoke 5/5 (local-ignore/qa-evidence/20260728-pr424-review-fixes/).
# Conflicts: # packages/coding-agent/src/core/extensions/builtin/goal/changes.md
# Conflicts: # packages/coding-agent/src/core/extensions/builtin/goal/changes.md
Summary
Root cause
A resumed 34 MB / ~3,400-entry session stayed above 100% CPU. A Node inspector profile was dominated by
visibleWidth,graphemeWidth,extractAnsiCode, andTUI.doRender.The release over-wide path guarded the diagnostic file write but eagerly constructed
crashDatafirst, mapping the entire rendered transcript throughvisibleWidthon every animated frame. The default Working message shimmer requested those frames every 32 ms, the indicator every 600 ms, and the goal ticker continued requesting identical footer labels every second after the display granularity changed to minutes.Tests
[3600, 3601, 3602, 3603, 3604, 3605]for one unchanged1hlabelpackages/tui: fullnpm testpassednpm run checkpassednpm run buildpassed--help,--version, offline model list, and unknown-option handlingBehavior
Small sessions retain the existing smooth 32 ms / 600 ms animation. Large histories still repaint immediately for tool, stream, status, and message events; only decorative periodic frames fall back to 60 seconds.
Summary by cubic
Prevents high CPU render loops in large sessions by throttling non‑essential TUI/agent timers while keeping event‑driven renders immediate. Over‑wide diagnostics now scan once in release mode; goal/footer and hook timers avoid redundant re-renders.
packages/tui: Build over‑wide diagnostics only in strict mode or on the first release dump; later frames truncate without rescanning. Adds__renderDiagnosticStats()for tests.packages/coding-agent:GoalElapsedTickerskips ticks when the formatted elapsed label is unchanged; clears its memo onsync()andstop()so goal switches render immediately.packages/coding-agent: ApplylargeSessionWorkingStatusInterval()to default Working timers — message and hook rows tick at 1s, the decorative indicator falls back to 60s. Small sessions keep 32ms/600ms. Threshold is sampled when timers start; customsetWorkingIndicator()options bypass this policy.Written for commit e25e27c. Summary will update on new commits.