Skip to content

Commit 218eca1

Browse files
committed
fix(cli): disclose a truncated burst, and clear a stale retry notice
Two review findings in `logs follow`, both verified against the code first. The page budget bounds one poll so an enormous burst cannot stall the follow, but on reaching it the live cursor was discarded: the remainder is older than everything collected and the next poll restarts at the newest page, so those runs were never printed and nothing said so. The budget stays — draining without one trades a bounded poll for unbounded buffering in a process meant to run for hours — but hitting it now warns on stderr, naming the count and pointing at `sim logs list`. That notice is written even off a terminal, because a piped log is where an unexplained hole is hardest to spot. The retry notice was cleared after the empty-rows check, so a poll that recovered but found nothing left "retrying in Ns…" on screen while the follow was already healthy. Clearing now happens as soon as a poll succeeds. The second test needed two failures to be worth anything: the teardown clears the line either way, so what separates fixed from broken is whether a bare erase lands before the second notice or only at the end. The first version passed against the bug.
1 parent aa0a1fe commit 218eca1

2 files changed

Lines changed: 103 additions & 15 deletions

File tree

packages/sim-cli/src/commands/protocol/logs-follow.test.ts

Lines changed: 45 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -247,6 +247,51 @@ describe('sim logs follow', () => {
247247
expect(stdout.join('')).not.toContain('retrying in')
248248
})
249249

250+
it('says so when a burst is larger than one poll may read', async () => {
251+
// The page budget bounds one poll so an enormous burst cannot stall the
252+
// follow, but the remainder is older than everything collected and the next
253+
// poll restarts at the newest page — so those runs are never coming, and a
254+
// hole the reader cannot see is worse than a slow poll.
255+
Object.defineProperty(process.stderr, 'isTTY', { value: true, configurable: true })
256+
const seed = row('seed', '2026-08-17T10:00:00.000Z')
257+
const budgeted = Array.from({ length: 10 }, (_, index) =>
258+
page([row(`burst_${index}`, `2026-08-17T10:01:0${index}.000Z`)], `cursor_${index}`)
259+
)
260+
respondWith([page([seed]), ...budgeted])
261+
262+
await follow('-n', '1')
263+
264+
expect(stderr.join('')).toContain('older ones were skipped')
265+
expect(stdout.join('')).not.toContain('older ones were skipped')
266+
})
267+
268+
it('clears a retry notice on the first healthy poll, even an empty one', async () => {
269+
// The clear used to sit after the empty check, so a poll that recovered but
270+
// found nothing left "retrying in Ns…" up while the follow was already
271+
// healthy. Asserted between two failures because the teardown clears the
272+
// line either way: what separates the two is whether a bare erase lands
273+
// BEFORE the second notice, or only at the end.
274+
Object.defineProperty(process.stderr, 'isTTY', { value: true, configurable: true })
275+
const first = row('run_1', '2026-08-17T10:00:01.000Z')
276+
respondWith([
277+
page([first]),
278+
new SimApiError('Service Unavailable', 503),
279+
page([first]),
280+
new SimApiError('Service Unavailable', 503),
281+
page([first]),
282+
])
283+
284+
await follow('-n', '1')
285+
286+
const bareErase = stderr.indexOf(`\r${String.fromCharCode(27)}[K`)
287+
const notices = stderr
288+
.map((line, index) => (line.includes('retrying in') ? index : -1))
289+
.filter((index) => index >= 0)
290+
expect(notices).toHaveLength(2)
291+
expect(bareErase).toBeGreaterThan(notices[0])
292+
expect(bareErase).toBeLessThan(notices[1])
293+
})
294+
250295
it('stays silent on stderr when it is not a terminal', async () => {
251296
Object.defineProperty(process.stderr, 'isTTY', { value: false, configurable: true })
252297
const first = row('run_1', '2026-08-17T10:00:01.000Z')

packages/sim-cli/src/commands/protocol/logs-follow.ts

Lines changed: 58 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -247,6 +247,15 @@ function createWriter(format: OutputFormat): RowWriter {
247247
export interface FollowStatus {
248248
/** Replaces the status line, if there is a terminal to draw it on. */
249249
note: (message: string) => void
250+
/**
251+
* Reports something the reader has to know, on its own line.
252+
*
253+
* Unlike {@link note} this is not progress and is never erased: it records
254+
* that rows are missing, which stays true after the follow moves on. It is
255+
* written even when stderr is not a terminal, because a piped log is exactly
256+
* where an unexplained hole is hardest to spot.
257+
*/
258+
warn: (message: string) => void
250259
/** Erases the line, if anything was ever written to it. */
251260
clear: () => void
252261
}
@@ -265,6 +274,13 @@ export function followStatus(): FollowStatus {
265274
reported = true
266275
process.stderr.write(`\r${chalk.dim(message)}${ERASE_LINE}`)
267276
},
277+
warn: (message) => {
278+
if (reported) {
279+
reported = false
280+
process.stderr.write(`\r${ERASE_LINE}`)
281+
}
282+
process.stderr.write(`warning: ${message}\n`)
283+
},
268284
clear: () => {
269285
if (!reported) return
270286
reported = false
@@ -370,30 +386,48 @@ function remember(state: FollowState, rows: LogRow[]): void {
370386
* holding one known row proves the rest of the list is older still, so walking
371387
* further would only re-read history the floor rejects anyway.
372388
*/
389+
/**
390+
* One poll's worth of new rows, and whether the page budget cut it short.
391+
*
392+
* A follow reads a bounded number of pages per poll so one enormous burst
393+
* cannot stall it indefinitely or buffer without limit. Reaching that bound
394+
* means older runs from the same burst will never be printed, which is worth
395+
* saying out loud rather than leaving the reader to notice a hole later.
396+
*/
397+
interface PollBatch {
398+
rows: LogRow[]
399+
truncated: boolean
400+
}
401+
373402
async function collectUnprinted(
374403
client: Pick<SimClient, 'request'>,
375404
path: string,
376405
query: Record<string, string | number | undefined>,
377406
state: FollowState,
378407
pageSize: number,
379408
maxPages: number
380-
): Promise<LogRow[]> {
381-
const fresh: LogRow[] = []
409+
): Promise<PollBatch> {
410+
const rows: LogRow[] = []
382411
let cursor: string | null = null
412+
let truncated = false
383413

384414
for (let page = 0; page < maxPages; page += 1) {
385415
const response: ListLogsResponse = await client.request<ListLogsResponse>(path, {
386416
query: { ...query, limit: pageSize, cursor },
387417
})
388-
const rows = response?.data ?? []
389-
const unprinted = rows.filter((row) => isUnprinted(state, row))
390-
fresh.push(...unprinted)
418+
const page_rows = response?.data ?? []
419+
const unprinted = page_rows.filter((row) => isUnprinted(state, row))
420+
rows.push(...unprinted)
391421

392422
cursor = response?.nextCursor ?? null
393-
if (!cursor || rows.length === 0 || unprinted.length < rows.length) break
423+
if (!cursor || page_rows.length === 0 || unprinted.length < page_rows.length) break
424+
// Every page so far was new and another is waiting, so the burst is larger
425+
// than one poll may read. The remainder is older than everything collected
426+
// here and the next poll restarts at the newest page, so it is not coming.
427+
if (page === maxPages - 1) truncated = true
394428
}
395429

396-
return fresh
430+
return { rows, truncated }
397431
}
398432

399433
/**
@@ -511,10 +545,10 @@ Examples:
511545
// The backlog page doubles as the seed: every run on it is recorded and
512546
// its oldest start time becomes the floor, so even `-n 0` anchors the
513547
// follow to now instead of replaying the workspace's whole history.
514-
const backlog = await collectUnprinted(client, path, query, state, Math.max(lines, 1), 1)
515-
remember(state, backlog)
516-
state.floor = backlog.at(-1)?.startedAt ?? null
517-
write(lines > 0 ? backlog.slice(0, lines).reverse() : [])
548+
const seed = await collectUnprinted(client, path, query, state, Math.max(lines, 1), 1)
549+
remember(state, seed.rows)
550+
state.floor = seed.rows.at(-1)?.startedAt ?? null
551+
write(lines > 0 ? seed.rows.slice(0, lines).reverse() : [])
518552

519553
let failures = 0
520554
while (!interrupt.interrupted()) {
@@ -524,7 +558,7 @@ Examples:
524558
)
525559
if (interrupt.interrupted()) break
526560

527-
let fresh: LogRow[]
561+
let fresh: PollBatch
528562
try {
529563
fresh = await collectUnprinted(
530564
client,
@@ -544,13 +578,22 @@ Examples:
544578
continue
545579
}
546580

581+
// Cleared on success rather than after the empty check: a poll that
582+
// recovers but finds nothing still ends the retry, and leaving the
583+
// notice up until rows happen to arrive reports a healthy follow as
584+
// still failing.
547585
failures = 0
548-
if (fresh.length === 0) continue
549586
status.clear()
550-
remember(state, fresh)
587+
if (fresh.truncated) {
588+
status.warn(
589+
`more than ${MAX_PAGES_PER_POLL * POLL_PAGE_SIZE} runs arrived at once; older ones were skipped — see sim logs list`
590+
)
591+
}
592+
if (fresh.rows.length === 0) continue
593+
remember(state, fresh.rows)
551594
// Reversed because the API answers newest-first while a terminal reads
552595
// downwards: the newest run has to end up on the last line.
553-
write(fresh.reverse())
596+
write(fresh.rows.reverse())
554597
}
555598
} finally {
556599
status.clear()

0 commit comments

Comments
 (0)