mirror of
https://github.com/Ark0N/Codeman.git
synced 2026-10-02 05:29:42 +02:00
perf: pace the refetch and back the tail poll off a quiet pane
Both of the dashboard's periodic reads hit endpoints that are far more expensive than their cadence assumed, and the cost lands on the SERVER's event loop, so it is paid by every browser client too. `GET /api/sessions/unified` is ~550ms against 11 live sessions: it scans every Claude transcript plus the lifecycle log, uncached, and republishes the search index. `scheduleRefresh()` was a 250ms trailing debounce with no floor, and a queued refresh re-ran the instant the previous one returned (by recursing, which also chained one pending promise per iteration), so a stream of events paced the refetches at the endpoint's own latency: with `session:updated` broadcast per session per 500ms while anything is working, the scans ran back to back. `resyncDelayMs()` now keeps ambient refetches 3s apart, measured start-to-start. The user's own actions call `refresh()` directly and are unaffected, so what this paces is only "notice what changed elsewhere". `GET /api/sessions/:id/terminal` is ~80-100ms: two `execSync` tmux calls, then the whole byte buffer normalized before the tail is taken. It was polled every second for as long as a live row was selected. It now backs off 1s, 2s, 4s, 5s while consecutive reads change nothing, and resets to 1s on any change, when the selection moves, when this dashboard sends input or answers a dialog, and on return from an attach. A pane that is printing is still read every second; a pane at its composer is not. The poll also kept running in three places it had nothing to draw for: the whole time the user was attached in tmux (an attach can last hours), and behind the message overlays that an async action opens (answered, killed, started), which are not keystroke-driven and so never reached the `afterInput()` path that stops it. `setInterval` becomes a chained `setTimeout`, since the delay now varies. Measured against the live server, same idle row selected, 25s window: 22 tail reads before, 5 after. With a working pane selected it stays at 22, which is the intended cadence for a pane whose output you are watching. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
+145
-18
@@ -108,14 +108,40 @@ const ESC_FLUSH_MS = 30;
|
||||
const TICK_MS = 500;
|
||||
/** A burst of SSE events (one session change fans out to several) becomes one refetch. */
|
||||
const RESYNC_DEBOUNCE_MS = 250;
|
||||
/**
|
||||
* Floor between two AMBIENT refetches, i.e. the ones an SSE event asks for.
|
||||
*
|
||||
* `GET /api/sessions/unified` is the expensive read in the app (~550ms measured
|
||||
* against 11 live sessions: it scans every Claude transcript plus the lifecycle
|
||||
* log, uncached, and republishes the search index), and the server broadcasts
|
||||
* `session:updated` per session per 500ms while anything is working. A trailing
|
||||
* debounce collapses a BURST but does not rate-limit a stream, so without a
|
||||
* floor the dashboard runs those scans back to back for as long as sessions are
|
||||
* busy, and the stall lands on every other client of the same server.
|
||||
*
|
||||
* A user's OWN actions bypass this (they call `refresh()` directly), so what it
|
||||
* paces is only "notice what changed elsewhere", where three seconds of
|
||||
* staleness on a status dot is invisible.
|
||||
*/
|
||||
const RESYNC_MIN_INTERVAL_MS = 3_000;
|
||||
/** Poll period once the client reports SSE is not carrying events. */
|
||||
const POLL_INTERVAL_MS = 2_000;
|
||||
/** Degraded mode re-probes this often, so a server that starts upgrades the TUI live. */
|
||||
const REPROBE_INTERVAL_MS = 10_000;
|
||||
/** Unified-list page size. RECENT is capped far lower by the model. */
|
||||
const UNIFIED_LIMIT = 60;
|
||||
/** How often the selected session's tail is re-read while the list has focus. */
|
||||
/** How often the selected session's tail is re-read while it is producing output. */
|
||||
const PREVIEW_INTERVAL_MS = 1_000;
|
||||
/**
|
||||
* Ceiling the tail poll backs off to once the pane stops changing.
|
||||
*
|
||||
* `GET /api/sessions/:id/terminal` is not a cheap read either (~80-100ms
|
||||
* measured): it runs two `execSync` tmux calls and normalizes the whole byte
|
||||
* buffer before it takes the tail, all of it blocking the server's event loop.
|
||||
* A pane at its composer prints nothing, so polling it every second buys
|
||||
* nothing; anything landing in the tail resets the cadence to fast again.
|
||||
*/
|
||||
const PREVIEW_MAX_INTERVAL_MS = 5_000;
|
||||
/** Tail size. Enough for a tall pane's last screens, small enough to poll every second. */
|
||||
const PREVIEW_TAIL_BYTES = 12 * 1024;
|
||||
/** Lines kept from a tail. The pane shows a fraction of these; the rest is headroom. */
|
||||
@@ -375,9 +401,47 @@ export function previewNoteFor(row: TuiRow | null, connection: TuiConnectionStat
|
||||
}
|
||||
|
||||
/**
|
||||
* Would painting `next` change anything? The preview polls once a second, and a
|
||||
* Delay before the next AMBIENT refetch: the debounce, unless that would land
|
||||
* inside the floor since the last one started, in which case it waits out the
|
||||
* rest of the floor. Measured start-to-start, so a slow scan cannot be followed
|
||||
* immediately by another one.
|
||||
*
|
||||
* `lastRefreshAt` of 0 means "never refreshed", which the arithmetic handles on
|
||||
* its own: the gap is enormous, so the first refetch pays the debounce only.
|
||||
*/
|
||||
export function resyncDelayMs(
|
||||
now: number,
|
||||
lastRefreshAt: number,
|
||||
debounceMs = RESYNC_DEBOUNCE_MS,
|
||||
minIntervalMs = RESYNC_MIN_INTERVAL_MS
|
||||
): number {
|
||||
return Math.max(debounceMs, minIntervalMs - (now - lastRefreshAt));
|
||||
}
|
||||
|
||||
/**
|
||||
* How long to wait before re-reading the selected session's tail, given how
|
||||
* many consecutive reads came back identical.
|
||||
*
|
||||
* Doubling from one second to a five-second ceiling, and ANY change resets the
|
||||
* count, so a pane that is printing is read every second while a pane sitting
|
||||
* at its composer costs one read every five. The counter is also reset when the
|
||||
* selection moves and when this dashboard sends input, so the read that should
|
||||
* show a reply is never the backed-off one.
|
||||
*/
|
||||
export function previewIntervalMs(
|
||||
unchangedReads: number,
|
||||
baseMs = PREVIEW_INTERVAL_MS,
|
||||
maxMs = PREVIEW_MAX_INTERVAL_MS
|
||||
): number {
|
||||
const steps = Math.min(Math.max(0, Math.trunc(unchangedReads)), 10);
|
||||
return Math.min(baseMs * 2 ** steps, maxMs);
|
||||
}
|
||||
|
||||
/**
|
||||
* Would painting `next` change anything? The preview polls on a timer, and a
|
||||
* quiet session returns the same bytes every time; comparing here is what keeps
|
||||
* that poll from bumping the model's revision and repainting the frame.
|
||||
* that poll from bumping the model's revision and repainting the frame, and it
|
||||
* is also what drives the poll's own backoff.
|
||||
*/
|
||||
export function samePreview(previous: TuiPreview | null, next: TuiPreview | null): boolean {
|
||||
if (previous === next) return true;
|
||||
@@ -643,11 +707,17 @@ class TuiApp {
|
||||
private noticeTimer: NodeJS.Timeout | null = null;
|
||||
private refreshing = false;
|
||||
private refreshQueued = false;
|
||||
/** When the last refresh STARTED, which is what `resyncDelayMs()` paces off. */
|
||||
private lastRefreshAt = 0;
|
||||
private picker: PickerRuntime | null = null;
|
||||
private pendingSelectId: string | null = null;
|
||||
/** Whose tail the preview is currently following; null when nothing is polled. */
|
||||
private previewSessionId: string | null = null;
|
||||
private previewFetching = false;
|
||||
/** Is the tail still worth re-reading? The chained timeout stops when it is not. */
|
||||
private previewFollowing = false;
|
||||
/** Consecutive tail reads that changed nothing; the poll's backoff counter. */
|
||||
private previewQuiet = 0;
|
||||
/** Bumped per search so a slow response cannot overwrite a newer query's results. */
|
||||
private searchSeq = 0;
|
||||
/** Approval ids the bell has already rung for. See `newApprovalIds`. */
|
||||
@@ -760,16 +830,25 @@ class TuiApp {
|
||||
|
||||
private scheduleRefresh(): void {
|
||||
if (this.resyncTimer) return;
|
||||
this.resyncTimer = setTimeout(() => {
|
||||
this.resyncTimer = null;
|
||||
void this.refresh();
|
||||
}, RESYNC_DEBOUNCE_MS);
|
||||
this.resyncTimer = setTimeout(
|
||||
() => {
|
||||
this.resyncTimer = null;
|
||||
void this.refresh();
|
||||
},
|
||||
resyncDelayMs(Date.now(), this.lastRefreshAt)
|
||||
);
|
||||
}
|
||||
|
||||
/**
|
||||
* Re-read everything the dashboard shows. Overlapping calls collapse: a burst
|
||||
* of events must not queue a burst of round trips, and the last one has to
|
||||
* still run or the list would sit one change behind.
|
||||
*
|
||||
* A call that arrived while this one was in flight is handed back to
|
||||
* `scheduleRefresh()` rather than run on the spot. Recursing there instead
|
||||
* (which is what this did) paced the refetches at the endpoint's own latency
|
||||
* and chained one pending promise per iteration, so a busy machine kept the
|
||||
* server scanning transcripts continuously.
|
||||
*/
|
||||
private async refresh(): Promise<void> {
|
||||
if (this.exiting) return;
|
||||
@@ -778,6 +857,9 @@ class TuiApp {
|
||||
return;
|
||||
}
|
||||
this.refreshing = true;
|
||||
// Stamped at the START, so the floor is start-to-start and a direct call
|
||||
// (an action of the user's own) also pushes the next ambient one out.
|
||||
this.lastRefreshAt = Date.now();
|
||||
try {
|
||||
if (this.model.connection === 'degraded') await this.refreshDegraded();
|
||||
else await this.refreshConnected();
|
||||
@@ -786,7 +868,7 @@ class TuiApp {
|
||||
}
|
||||
if (this.refreshQueued && !this.exiting) {
|
||||
this.refreshQueued = false;
|
||||
await this.refresh();
|
||||
this.scheduleRefresh();
|
||||
}
|
||||
}
|
||||
|
||||
@@ -909,26 +991,44 @@ class TuiApp {
|
||||
return;
|
||||
}
|
||||
|
||||
this.previewFollowing = true;
|
||||
if (changed) {
|
||||
// A different pane, so what the last one printed says nothing about how
|
||||
// fast this one needs reading.
|
||||
this.previewQuiet = 0;
|
||||
// Null rather than an empty tail: the renderer reads that as "loading",
|
||||
// while empty lines would claim the session has printed nothing.
|
||||
this.applyPreview(null);
|
||||
void this.fetchPreview();
|
||||
}
|
||||
if (!this.previewTimer) {
|
||||
this.previewTimer = setInterval(() => void this.fetchPreview(), PREVIEW_INTERVAL_MS);
|
||||
}
|
||||
this.armPreview();
|
||||
}
|
||||
|
||||
/**
|
||||
* Arm the next tail read. A chained timeout rather than an interval, because
|
||||
* the delay depends on how long the pane has been quiet, and re-arming is the
|
||||
* LAST thing each read does so a slow response can never stack two in flight.
|
||||
*/
|
||||
private armPreview(): void {
|
||||
if (this.previewTimer || !this.previewFollowing || this.exiting) return;
|
||||
this.previewTimer = setTimeout(() => {
|
||||
this.previewTimer = null;
|
||||
void this.fetchPreview().finally(() => this.armPreview());
|
||||
}, previewIntervalMs(this.previewQuiet));
|
||||
}
|
||||
|
||||
private stopPreview(): void {
|
||||
this.previewFollowing = false;
|
||||
if (!this.previewTimer) return;
|
||||
clearInterval(this.previewTimer);
|
||||
clearTimeout(this.previewTimer);
|
||||
this.previewTimer = null;
|
||||
}
|
||||
|
||||
private applyPreview(preview: TuiPreview | null): void {
|
||||
if (samePreview(this.model.preview, preview)) return;
|
||||
/** Paint a preview, reporting whether it actually differed from what is up. */
|
||||
private applyPreview(preview: TuiPreview | null): boolean {
|
||||
if (samePreview(this.model.preview, preview)) return false;
|
||||
this.model.setPreview(preview);
|
||||
return true;
|
||||
}
|
||||
|
||||
private async fetchPreview(): Promise<void> {
|
||||
@@ -939,12 +1039,17 @@ class TuiApp {
|
||||
const raw = await this.client.fetchTerminalTail(sessionId, PREVIEW_TAIL_BYTES);
|
||||
if (this.previewSessionId !== sessionId) return;
|
||||
const lines = toDisplayLines(dropSeveredEscape(raw)).slice(-PREVIEW_MAX_LINES);
|
||||
this.applyPreview({ sessionId, lines });
|
||||
// An identical tail is what the backoff counts; anything new resets it, so
|
||||
// a pane that starts printing again is back to one read a second.
|
||||
if (this.applyPreview({ sessionId, lines })) this.previewQuiet = 0;
|
||||
else this.previewQuiet++;
|
||||
} catch {
|
||||
// A tail that cannot be read is a pane-level fact, not a connection one:
|
||||
// the list stays exactly as it is and only this pane says so.
|
||||
// the list stays exactly as it is and only this pane says so. It counts as
|
||||
// quiet either way, so a pane that cannot be read is not retried hard.
|
||||
if (this.previewSessionId !== sessionId) return;
|
||||
this.applyPreview({ sessionId, lines: [], error: "could not read that session's terminal" });
|
||||
this.previewQuiet++;
|
||||
} finally {
|
||||
this.previewFetching = false;
|
||||
}
|
||||
@@ -1269,6 +1374,10 @@ class TuiApp {
|
||||
|
||||
private message(tone: 'info' | 'warn' | 'err', text: string): void {
|
||||
this.model.setMessage({ tone, text });
|
||||
// An overlay hides the preview pane, so stop re-reading the tail behind it.
|
||||
// Keystroke-driven overlays get this from `afterInput()`; the ones an async
|
||||
// action opens (answered, killed, started) would otherwise keep polling.
|
||||
this.updatePreview();
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -1278,6 +1387,7 @@ class TuiApp {
|
||||
*/
|
||||
private notice(text: string): void {
|
||||
this.model.setMessage({ tone: 'info', text });
|
||||
this.updatePreview();
|
||||
const shown = this.model.message;
|
||||
if (this.noticeTimer) clearTimeout(this.noticeTimer);
|
||||
this.noticeTimer = setTimeout(() => {
|
||||
@@ -1305,6 +1415,8 @@ class TuiApp {
|
||||
this.paint();
|
||||
return;
|
||||
}
|
||||
// Answering a dialog unblocks the agent, so the pane starts printing again.
|
||||
if (result.ok) this.previewQuiet = 0;
|
||||
await this.refresh();
|
||||
if (result.ok) this.notice(`answered ${item.sessionName || item.sessionId.slice(0, 8)}`);
|
||||
// The server re-captures the pane before it types, so this is the normal
|
||||
@@ -1342,6 +1454,9 @@ class TuiApp {
|
||||
}
|
||||
try {
|
||||
await this.client.sendInput(sessionId, line);
|
||||
// The pane is about to print the reply, so read it at the fast cadence
|
||||
// however long it had been sitting quiet before this.
|
||||
this.previewQuiet = 0;
|
||||
await this.refresh();
|
||||
this.notice('sent');
|
||||
} catch (error) {
|
||||
@@ -1473,6 +1588,12 @@ class TuiApp {
|
||||
return;
|
||||
}
|
||||
|
||||
// tmux is about to own this terminal. The dashboard is not on screen, and
|
||||
// the pane the preview would keep re-reading is the one the user is now
|
||||
// looking at directly, so the poll stops for the whole handoff (an attach
|
||||
// can last hours).
|
||||
this.stopPreview();
|
||||
|
||||
if (plan.kind === 'switch') {
|
||||
// The client this TUI draws on is about to show another session, so the
|
||||
// dashboard has nothing left to draw and no reason to keep polling.
|
||||
@@ -1491,6 +1612,10 @@ class TuiApp {
|
||||
this.stdout.write(`${plan.hint}\n`);
|
||||
const result = spawnSync(plan.file, plan.args, { stdio: 'inherit' });
|
||||
this.screen.enter();
|
||||
// Whatever happened in the pane happened while nobody was reading it, so the
|
||||
// first tail after a detach must not be a backed-off one.
|
||||
this.previewQuiet = 0;
|
||||
this.updatePreview();
|
||||
this.paint(true);
|
||||
if (result.error) {
|
||||
this.message('err', `tmux attach failed: ${getErrorMessage(result.error)}`);
|
||||
@@ -1674,12 +1799,14 @@ class TuiApp {
|
||||
private quit(code: number): void {
|
||||
if (this.exiting) return;
|
||||
this.exiting = true;
|
||||
for (const timer of [this.escTimer, this.resyncTimer, this.searchTimer, this.noticeTimer]) {
|
||||
for (const timer of [this.escTimer, this.resyncTimer, this.searchTimer, this.noticeTimer, this.previewTimer]) {
|
||||
if (timer) clearTimeout(timer);
|
||||
}
|
||||
for (const timer of [this.tickTimer, this.pollTimer, this.probeTimer, this.previewTimer]) {
|
||||
for (const timer of [this.tickTimer, this.pollTimer, this.probeTimer]) {
|
||||
if (timer) clearInterval(timer);
|
||||
}
|
||||
// Not only the timer: the chain re-arms itself, so the flag has to go too.
|
||||
this.previewFollowing = false;
|
||||
this.escTimer = null;
|
||||
this.resyncTimer = null;
|
||||
this.searchTimer = null;
|
||||
|
||||
@@ -20,7 +20,9 @@ import {
|
||||
helpKeysFor,
|
||||
isSelfSession,
|
||||
planAttach,
|
||||
previewIntervalMs,
|
||||
previewNoteFor,
|
||||
resyncDelayMs,
|
||||
sameFrame,
|
||||
samePreview,
|
||||
shouldAnimate,
|
||||
@@ -259,6 +261,29 @@ describe('the preview policy', () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe('the refetch and tail-read cadence', () => {
|
||||
it('debounces a burst but paces a stream, measured from the last start', () => {
|
||||
// Nothing has been refetched yet: pay the debounce and nothing more.
|
||||
expect(resyncDelayMs(10_000, 0, 250, 3_000)).toBe(250);
|
||||
// A refetch that started 2.9s ago: wait out the rest of the floor.
|
||||
expect(resyncDelayMs(10_000, 9_900, 250, 3_000)).toBe(2_900);
|
||||
// Past the floor: back to the debounce, never below it.
|
||||
expect(resyncDelayMs(10_000, 6_000, 250, 3_000)).toBe(250);
|
||||
expect(resyncDelayMs(10_000, 1_000, 250, 3_000)).toBe(250);
|
||||
});
|
||||
|
||||
it('reads a printing pane every second and a quiet one every five', () => {
|
||||
expect(previewIntervalMs(0, 1_000, 5_000)).toBe(1_000);
|
||||
expect(previewIntervalMs(1, 1_000, 5_000)).toBe(2_000);
|
||||
expect(previewIntervalMs(2, 1_000, 5_000)).toBe(4_000);
|
||||
// The ceiling holds however long the pane stays quiet, and a silly counter
|
||||
// cannot overflow the doubling into Infinity.
|
||||
expect(previewIntervalMs(3, 1_000, 5_000)).toBe(5_000);
|
||||
expect(previewIntervalMs(50, 1_000, 5_000)).toBe(5_000);
|
||||
expect(previewIntervalMs(-5, 1_000, 5_000)).toBe(1_000);
|
||||
});
|
||||
});
|
||||
|
||||
describe('the repaint test', () => {
|
||||
const key = { revision: 3, cols: 100, rows: 30, tick: 0 };
|
||||
|
||||
|
||||
@@ -60,6 +60,12 @@ const terminals = new Map<string, string>();
|
||||
* ago. A row dated by the wrong one of those reads `10m` instead of `1m`.
|
||||
*/
|
||||
let liveState: Array<Record<string, unknown>> = [];
|
||||
/**
|
||||
* Tail reads the preview pane has asked for. On the real server that route runs
|
||||
* two synchronous tmux calls and normalizes the whole byte buffer, so how often
|
||||
* a quiet pane is re-read is a property worth pinning.
|
||||
*/
|
||||
let terminalReads = 0;
|
||||
/** Everything the TUI posted, so a test can assert on the exact body. */
|
||||
const answered: Array<{ id: string; body: Record<string, unknown> }> = [];
|
||||
const inputs: Array<{ sessionId: string; body: Record<string, unknown> }> = [];
|
||||
@@ -281,6 +287,7 @@ beforeAll(async () => {
|
||||
|
||||
const previewFor = sessionRoute(url, 'terminal');
|
||||
if (previewFor) {
|
||||
terminalReads++;
|
||||
return sendJson(res, { success: true, data: { terminalBuffer: terminals.get(previewFor) ?? '' } });
|
||||
}
|
||||
|
||||
@@ -492,6 +499,22 @@ describe('codeman tui (under a pty)', () => {
|
||||
await waitFor(() => rowFor(output, 'w2-beta').startsWith('>'), 'the up arrow to move the cursor');
|
||||
});
|
||||
|
||||
it('keeps re-reading the tail, but backs off while the pane stays quiet', async () => {
|
||||
await selectRow('w2-beta');
|
||||
// Let the selection's own immediate read land, then measure a window in
|
||||
// which nothing writes to the pane.
|
||||
await new Promise((done) => setTimeout(done, 400));
|
||||
const before = terminalReads;
|
||||
await new Promise((done) => setTimeout(done, 6_000));
|
||||
const reads = terminalReads - before;
|
||||
// Still following: a chain that forgot to re-arm would freeze the pane at
|
||||
// whatever it last showed, which no frame assertion would notice.
|
||||
expect(reads).toBeGreaterThan(0);
|
||||
// A fixed one-second poll would be six. The ladder (1s, 2s, 4s, then the
|
||||
// 5s ceiling) cannot exceed four in this window.
|
||||
expect(reads).toBeLessThanOrEqual(4);
|
||||
}, 20_000);
|
||||
|
||||
it('picks up a session announced over SSE', async () => {
|
||||
sessions = [
|
||||
...sessions,
|
||||
|
||||
Reference in New Issue
Block a user