From 624039a7f24d678f6ade4503463a2654d5b39fa1 Mon Sep 17 00:00:00 2001 From: QiaolongLi1201 Date: Mon, 12 Oct 2026 01:20:41 +0800 Subject: [PATCH 1/2] feat(cli): O99 show real progress during long runs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Emit real progress at least every 60s on TUI and --print (stderr only): tool start/end summaries, long-tool heartbeats via tool_progress, and thinking-wait lines. Map existing tool_execution_progress heartbeats; no empty working… slogans; unfinished runs get a clear last line on the progress path (full false-success exit-code gate depends on O98/#94). Display only — no safety/scheduling change. --- src/cli/oneshot.ts | 12 + src/cli/output.ts | 75 +++- src/cli/print.ts | 3 + src/cli/run-progress.ts | 407 ++++++++++++++++++++++ src/cli/tui/render-bridge.ts | 8 + src/cli/tui/transcript.ts | 46 ++- src/core/agent/moss-agent-loop-adapter.ts | 9 + src/core/agent/moss-agent-types.ts | 6 + test/cli-output.spec.mjs | 16 +- test/o99-progress.spec.mjs | 318 +++++++++++++++++ 10 files changed, 868 insertions(+), 32 deletions(-) create mode 100644 src/cli/run-progress.ts create mode 100644 test/o99-progress.spec.mjs diff --git a/src/cli/oneshot.ts b/src/cli/oneshot.ts index c2528131..d0a2a905 100644 --- a/src/cli/oneshot.ts +++ b/src/cli/oneshot.ts @@ -29,6 +29,7 @@ import { buildGitStatusSnapshot } from '../context/git-status-snapshot.js'; import { acceptanceShell } from '../core/task/acceptance-command.js'; import { runStopHooks, type StopHookResult } from './hooks.js'; import { runProcess } from '../utils/run-process.js'; +import { createRunProgressTracker } from './run-progress.js'; /** Format the oneshot exit warning when background work outlives the wait window. */ export function formatOneshotStillRunningBackgroundNotice( @@ -405,6 +406,15 @@ export async function runOneShot( const stdout = options.stdout ?? process.stdout; const workspaceDir = options.cwd ?? process.cwd(); const renderer = outputFormat === 'text' ? createCliRunRenderer({ workspaceDir }) : null; + // O99: json / stream-json have no text renderer — still emit progress on stderr. + const jsonProgress = + outputFormat === 'text' + ? null + : createRunProgressTracker({ + sink: { write: (line) => process.stderr.write(`${line}\n`) }, + zh: isZhLocale(), + emitToolBoundaries: true, + }); let pricingOverrides: ReturnType | undefined; try { @@ -534,6 +544,7 @@ export async function runOneShot( renderer?.handle(event); rememberStructuredResult(structuredEvents); } else { + jsonProgress?.onEvent(event); writeStructured(structuredEvents); } } @@ -620,6 +631,7 @@ export async function runOneShot( } finally { try { renderer?.dispose?.(); + jsonProgress?.dispose(); } catch { /* ignore */ } diff --git a/src/cli/output.ts b/src/cli/output.ts index 9f603bda..40d34647 100644 --- a/src/cli/output.ts +++ b/src/cli/output.ts @@ -30,6 +30,13 @@ import { tui, } from './tui/copy.js'; import { noteToolForVerifyHint } from './verify-hint.js'; +import { + createRunProgressTracker, + formatToolRunningLine, + formatUnfinishedLine, + unfinishedReasonFromStop, + type RunProgressTracker, +} from './run-progress.js'; const CODE_EDIT_TOOLS = new Set([ 'write_file', @@ -453,6 +460,9 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { const detailMode = options.detailMode ?? resolveCliDetailMode(); const interactive = options.interactive ?? Boolean((stderr as NodeJS.WriteStream).isTTY); const spinner = interactive ? new CliSpinner(stderr) : null; + // O99: heartbeat + long-tool progress on stderr. Tool start/end stay with this + // renderer so we do not double-print; empty "working…" slogans are not used. + let progress: RunProgressTracker | undefined; const state: RendererState = { answerOpen: false, answerStarted: false, @@ -561,7 +571,27 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { } }); + function ensureProgress(): RunProgressTracker { + if (!progress) { + progress = createRunProgressTracker({ + sink: { + write(line: string) { + if (isQuiet) return; + breakAnswerForStatus(); + spinner?.stop(); + stderrLine(`${mark()} ${line}`); + }, + }, + zh: isZhLocale(), + emitToolBoundaries: false, + }); + } + return progress; + } + function handle(event: MossAgentEvent): void { + // O99 progress tracker (thinking wait / tool_progress). Quiet mode skips it. + if (!isQuiet) ensureProgress().onEvent(event); switch (event.type) { case 'turn_start': if (!isQuiet) { @@ -570,13 +600,11 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { if (isVerbose) { stderrLine(`${mark()} thinking${ui.dim(` (turn ${event.turn})`)}`); } else if (interactive) { - spinner?.start(`Working${event.turn > 1 ? `… (turn ${event.turn})` : ''}`); - } else if (event.turn > 2) { - // Oneshot / headless: suppress the first two turns (normal single-tool - // calls don't need a "working" message). Only signal turn 3+ which - // indicates a genuine multi-step tool loop where the user needs feedback. - stderrLine(ui.dim(`working…`)); + // Real label comes from tool_start / thinking-wait; keep spinner alive + // without empty rotating slogans. + spinner?.start(isZhLocale() ? '处理中' : 'Working'); } + // Non-interactive: no empty "working…" — O99 heartbeat covers silence. state.thinkingNoted = true; } break; @@ -624,6 +652,11 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { spinner?.stop(); state.toolStartTimes.set(event.toolCallId, Date.now()); state.toolInputs.set(event.toolCallId, event.input); + if (!isQuiet && interactive) { + const target = extractToolTarget(event.toolName, event.input); + const label = target ? `${event.toolName}(${target})` : event.toolName; + spinner?.start(isZhLocale() ? `正在调用 ${label}` : `Calling ${label}`); + } noteToolForVerifyHint( state, event.toolName, @@ -652,6 +685,15 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { } break; } + case 'tool_progress': { + if (!isQuiet && interactive) { + const input = state.toolInputs.get(event.toolCallId) ?? {}; + const line = formatToolRunningLine(event.toolName, input, event.elapsedSec, isZhLocale()); + spinner?.stop(); + spinner?.start(line); + } + break; + } case 'tool_end': { if (!isQuiet) { const startedAt = state.toolStartTimes.get(event.toolCallId); @@ -993,10 +1035,18 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { state.answerStarted = false; const stopReason = event.result?.stopReason; - if (stopReason === 'max_turns_reached' || stopReason === 'tool_followup_cap_reached') { - stderrLine( - `${mark('fail')} stopped at the turn limit before finishing — the task is paused, not complete. Continue with ${ui.bold('moss resume --last')} (or ${ui.bold('moss --continue')}).` - ); + const unfinished = unfinishedReasonFromStop(stopReason, isZhLocale()); + if (unfinished) { + // O99 / O98 alignment: never end on a half-done progress line with + // success wording. Clear last-line reason; exit code is set by oneshot. + stderrLine(`${mark('fail')} ${formatUnfinishedLine(unfinished, isZhLocale())}`); + if (stopReason === 'max_turns_reached' || stopReason === 'tool_followup_cap_reached') { + stderrLine( + isZhLocale() + ? `${mark('fail')} 可用 ${ui.bold('moss resume --last')}（或 ${ui.bold('moss --continue')}）继续。` + : `${mark('fail')} Continue with ${ui.bold('moss resume --last')} (or ${ui.bold('moss --continue')}).` + ); + } } else if (!isQuiet && state.editedJsTs && !state.ranTests) { // Only suggest npm test when JS/TS files were edited — avoid false // positives when the agent only writes Python, docs, or other files. @@ -1026,6 +1076,11 @@ export function createCliRunRenderer(options: CliRunRendererOptions = {}) { } catch { /* ignore */ } + try { + progress?.dispose(); + } catch { + /* ignore */ + } try { unsubscribeBackground(); } catch { diff --git a/src/cli/print.ts b/src/cli/print.ts index 5bb79f7c..9e982413 100644 --- a/src/cli/print.ts +++ b/src/cli/print.ts @@ -613,6 +613,9 @@ export function formatHeadlessStreamEvent( if (event.keptToolNames !== undefined) compaction.kept_tool_names = event.keptToolNames; return [compaction]; } + case 'tool_progress': + // O99: progress is stderr-only; never appear on stdout/JSON stream. + return []; case 'microcompact': case 'retry': return []; diff --git a/src/cli/run-progress.ts b/src/cli/run-progress.ts new file mode 100644 index 00000000..aed80fb2 --- /dev/null +++ b/src/cli/run-progress.ts @@ -0,0 +1,407 @@ +/** + * O99 — run progress for long tasks. + * + * Display-only: does not change tool scheduling, safety, or approvals. + * Progress lines go to stderr (or a sink); stdout stays for the final answer. + * + * Sources (priority): + * 1. tool start / end (name + file or command summary) + * 2. long-running tool heartbeats (tool_progress) + * 3. model thinking with no tool for ≥30s — 「正在推理，已等待 Ns」 + * Heartbeat: if nothing real for 60s, emit a thinking-wait line (never silent). + */ +import type { MossAgentEvent } from '../core/index.js'; + +export const THINKING_WAIT_INTERVAL_MS = 30_000; +export const HEARTBEAT_MAX_GAP_MS = 60_000; + +export type ProgressLineKind = + | 'tool_start' + | 'tool_end' + | 'tool_progress' + | 'thinking_wait' + | 'done' + | 'unfinished'; + +export interface ProgressLine { + kind: ProgressLineKind; + text: string; + at: number; +} + +export interface RunProgressSink { + write(line: string): void; +} + +export interface RunProgressClock { + now(): number; + setInterval(handler: () => void, ms: number): { clear(): void }; +} + +export interface CreateRunProgressTrackerOptions { + sink: RunProgressSink; + zh?: boolean; + /** When false, tool_start / tool_end are not written (caller already prints them). */ + emitToolBoundaries?: boolean; + thinkingWaitIntervalMs?: number; + heartbeatMaxGapMs?: number; + clock?: RunProgressClock; +} + +const EXEC_LIKE = new Set(['exec', 'device_exec', 'docker_exec', 'exec_background']); + +function defaultClock(): RunProgressClock { + return { + now: () => Date.now(), + setInterval(handler, ms) { + const id = setInterval(handler, ms); + // Do not keep the Node process alive solely for progress heartbeats + // (oneshot/tests that forget dispose would otherwise hang). + if (typeof (id as NodeJS.Timeout).unref === 'function') { + (id as NodeJS.Timeout).unref(); + } + return { clear: () => clearInterval(id) }; + }, + }; +} + +function clip(text: string, max: number): string { + const one = text.replace(/\s+/g, ' ').trim(); + if (one.length <= max) return one; + return `${one.slice(0, Math.max(0, max - 1)).trimEnd()}…`; +} + +/** File path / command / pattern summary for a tool call. */ +export function summarizeToolTarget(toolName: string, input: Record = {}): string { + const pick = (...keys: string[]): string => { + for (const key of keys) { + const value = input[key]; + if (typeof value === 'string' && value.trim()) return value.trim(); + } + return ''; + }; + + if ( + toolName === 'read_file' || + toolName === 'write_file' || + toolName === 'edit_file' || + toolName === 'move_file' || + toolName === 'apply_patch' + ) { + return clip(pick('path', 'filePath', 'file_path', 'source', 'destination'), 72); + } + if (toolName === 'multi_edit' && Array.isArray(input.edits)) { + const paths = (input.edits as Array>) + .map((e) => (typeof e.path === 'string' ? e.path : '')) + .filter(Boolean); + if (paths.length === 1) return clip(paths[0]!.replace(/\\/g, '/'), 72); + if (paths.length > 1) { + return clip(`${paths[0]} +${paths.length - 1} more`.replace(/\\/g, '/'), 72); + } + } + if (EXEC_LIKE.has(toolName)) { + const command = pick('command'); + return command ? clip(command, 72) : ''; + } + if (toolName === 'search_code' || toolName === 'search_files') { + return clip(pick('pattern', 'query'), 40); + } + if (toolName === 'web_fetch') return clip(pick('url'), 60); + return clip(pick('path', 'file_path', 'command', 'pattern', 'query', 'goal', 'url'), 72); +} + +export function formatToolProgressLabel( + toolName: string, + input: Record = {} +): string { + const target = summarizeToolTarget(toolName, input); + return target ? `${toolName}(${target})` : toolName; +} + +/** Bucket elapsed ms into 30s steps (30, 60, 90, …). Minimum 30. */ +export function thinkingWaitSeconds(elapsedMs: number, stepMs = THINKING_WAIT_INTERVAL_MS): number { + const step = Math.max(1, stepMs); + const n = Math.floor(elapsedMs / step) * (step / 1000); + return Math.max(step / 1000, n); +} + +export function formatThinkingWaitLine(elapsedMs: number, zh: boolean): string { + const n = thinkingWaitSeconds(elapsedMs); + return zh ? `正在推理，已等待 ${n}s` : `Still reasoning, waited ${n}s`; +} + +export function formatToolStartLine( + toolName: string, + input: Record, + zh: boolean +): string { + const label = formatToolProgressLabel(toolName, input); + return zh ? `正在调用 ${label}` : `Calling ${label}`; +} + +export function formatToolEndLine( + toolName: string, + input: Record, + zh: boolean, + isError: boolean +): string { + const label = formatToolProgressLabel(toolName, input); + if (zh) return isError ? `调用失败 ${label}` : `已完成 ${label}`; + return isError ? `Failed ${label}` : `Finished ${label}`; +} + +export function formatToolRunningLine( + toolName: string, + input: Record, + elapsedSec: number, + zh: boolean +): string { + const label = formatToolProgressLabel(toolName, input); + const sec = Math.max(0, Math.round(elapsedSec)); + return zh ? `正在跑 ${label} · 已 ${sec}s` : `Running ${label} · ${sec}s`; +} + +export function formatUnfinishedLine(reason: string, zh: boolean): string { + const detail = reason.replace(/\s+/g, ' ').trim() || (zh ? '任务未完成' : 'task unfinished'); + return zh ? `未完成：${detail}` : `Unfinished: ${detail}`; +} + +export function formatDoneLine(zh: boolean): string { + return zh ? '已完成' : 'Done'; +} + +export function unfinishedReasonFromStop( + stopReason: string | undefined, + zh: boolean +): string | undefined { + if (!stopReason) return undefined; + if (stopReason === 'max_turns_reached' || stopReason === 'tool_followup_cap_reached') { + return zh ? '已到回合上限，任务暂停未完成' : 'hit the turn limit before finishing'; + } + if (stopReason === 'tool_budget_reached') { + return zh ? '工具预算用尽，任务未完成' : 'tool budget reached before finishing'; + } + if (stopReason?.startsWith('budget_')) { + return zh ? '运行预算用尽，任务未完成' : 'run budget exceeded before finishing'; + } + if (stopReason === 'output_limit' || stopReason === 'max_tokens' || stopReason === 'length') { + return zh ? '输出长度上限，回答不完整' : 'output limit reached; answer is incomplete'; + } + if (stopReason === 'aborted_by_user') { + return zh ? '用户中断' : 'interrupted by user'; + } + if (stopReason === 'error') { + return zh ? '执行出错，任务未完成' : 'error during execution'; + } + return undefined; +} + +export interface RunProgressTracker { + onEvent(event: MossAgentEvent): void; + /** Record activity without emitting (e.g. when another renderer already printed the tool line). */ + noteActivity(at?: number): void; + dispose(): void; + /** Test helper: emitted lines in order. */ + lines(): readonly ProgressLine[]; +} + +/** + * Tracks silence and emits thinking-wait / tool-progress lines. + * Empty slogans (`working…` / rotating verbs) are never emitted. + */ +export function createRunProgressTracker( + options: CreateRunProgressTrackerOptions +): RunProgressTracker { + const zh = options.zh === true; + const emitToolBoundaries = options.emitToolBoundaries !== false; + const waitInterval = options.thinkingWaitIntervalMs ?? THINKING_WAIT_INTERVAL_MS; + const maxGap = options.heartbeatMaxGapMs ?? HEARTBEAT_MAX_GAP_MS; + const clock = options.clock ?? defaultClock(); + const emitted: ProgressLine[] = []; + + let lastEmitAt = clock.now(); + let thinkingSince: number | undefined; + let lastThinkingBucket = 0; + let activeTool: + | { toolCallId: string; toolName: string; input: Record } + | undefined; + let disposed = false; + let timer: { clear(): void } | undefined; + + function emit(kind: ProgressLineKind, text: string, at = clock.now()): void { + // Dedup: never stack the exact same progress text ≥3 times in a row. + const recent = emitted.slice(-2); + if (recent.length === 2 && recent.every((line) => line.text === text)) { + return; + } + emitted.push({ kind, text, at }); + lastEmitAt = at; + options.sink.write(text); + } + + function beginThinking(at = clock.now()): void { + if (thinkingSince === undefined) { + thinkingSince = at; + lastThinkingBucket = 0; + } + } + + function endThinking(): void { + thinkingSince = undefined; + lastThinkingBucket = 0; + } + + function maybeEmitThinkingWait(at = clock.now()): void { + if (activeTool) return; + if (thinkingSince === undefined) return; + const elapsed = at - thinkingSince; + if (elapsed < waitInterval) return; + const bucket = thinkingWaitSeconds(elapsed, waitInterval); + if (bucket === lastThinkingBucket) { + // Still force a heartbeat if we have been silent too long. + if (at - lastEmitAt < maxGap) return; + } + lastThinkingBucket = bucket; + emit('thinking_wait', formatThinkingWaitLine(elapsed, zh), at); + } + + function tick(): void { + if (disposed) return; + const at = clock.now(); + if (activeTool) { + // Tool heartbeats come from tool_progress events; only fill a 60s gap. + if (at - lastEmitAt >= maxGap) { + emit( + 'tool_progress', + formatToolRunningLine( + activeTool.toolName, + activeTool.input, + Math.round((at - lastEmitAt) / 1000), + zh + ), + at + ); + } + return; + } + if (thinkingSince === undefined) beginThinking(at); + maybeEmitThinkingWait(at); + if (at - lastEmitAt >= maxGap) { + maybeEmitThinkingWait(at); + if (at - lastEmitAt >= maxGap) { + const elapsed = thinkingSince !== undefined ? at - thinkingSince : maxGap; + emit('thinking_wait', formatThinkingWaitLine(elapsed, zh), at); + } + } + } + + timer = clock.setInterval(tick, Math.min(waitInterval, maxGap, 5_000)); + + return { + noteActivity(at = clock.now()) { + lastEmitAt = at; + }, + onEvent(event: MossAgentEvent) { + if (disposed) return; + const at = clock.now(); + switch (event.type) { + case 'turn_start': + activeTool = undefined; + beginThinking(at); + // Do not emit empty "working…" — wait for a real tool or the 30s wait. + break; + case 'thinking_delta': + beginThinking(at); + lastEmitAt = at; // deltas count as activity for the 60s gap, but no line spam + break; + case 'text_delta': + endThinking(); + lastEmitAt = at; + break; + case 'tool_start': { + endThinking(); + activeTool = { + toolCallId: event.toolCallId, + toolName: event.toolName, + input: event.input, + }; + if (emitToolBoundaries) { + emit('tool_start', formatToolStartLine(event.toolName, event.input, zh), at); + } else { + lastEmitAt = at; + } + break; + } + case 'tool_progress': { + const input = activeTool?.input ?? {}; + emit( + 'tool_progress', + formatToolRunningLine(event.toolName, input, event.elapsedSec, zh), + at + ); + break; + } + case 'tool_end': { + const input = activeTool?.input ?? {}; + if (emitToolBoundaries) { + emit('tool_end', formatToolEndLine(event.toolName, input, zh, event.isError), at); + } else { + lastEmitAt = at; + } + activeTool = undefined; + beginThinking(at); + break; + } + case 'retry': + endThinking(); + beginThinking(at); + lastEmitAt = at; + break; + case 'error': { + endThinking(); + activeTool = undefined; + if (emitToolBoundaries) { + emit( + 'unfinished', + formatUnfinishedLine( + event.errorSurface?.userMessage?.trim() || + (typeof event.error === 'string' ? event.error : '') || + (zh ? '执行出错' : 'error'), + zh + ), + at + ); + } else { + lastEmitAt = at; + } + break; + } + case 'done': { + activeTool = undefined; + endThinking(); + if (!emitToolBoundaries) { + lastEmitAt = at; + break; + } + const unfinished = unfinishedReasonFromStop(event.result?.stopReason, zh); + if (unfinished) { + emit('unfinished', formatUnfinishedLine(unfinished, zh), at); + } else { + emit('done', formatDoneLine(zh), at); + } + break; + } + default: + break; + } + }, + dispose() { + disposed = true; + timer?.clear(); + timer = undefined; + }, + lines() { + return emitted; + }, + }; +} diff --git a/src/cli/tui/render-bridge.ts b/src/cli/tui/render-bridge.ts index 5f570c0b..0c96399e 100644 --- a/src/cli/tui/render-bridge.ts +++ b/src/cli/tui/render-bridge.ts @@ -541,6 +541,14 @@ export function applyAgentEvent(store: TuiStore, event: MossAgentEvent): void { store.version++; break; } + case 'tool_progress': { + // O99: long-running tool heartbeat — keep the live label fresh with elapsed. + const input = store.run.toolInputs.get(event.toolCallId) ?? {}; + const base = toolLabel(event.toolName, input); + store.run.toolLine = `${base} · ${Math.max(0, Math.round(event.elapsedSec))}s`; + store.version++; + break; + } case 'tool_start': { closeThinking(store); store.run.retry = undefined; diff --git a/src/cli/tui/transcript.ts b/src/cli/tui/transcript.ts index 4417d2d6..7258287a 100644 --- a/src/cli/tui/transcript.ts +++ b/src/cli/tui/transcript.ts @@ -37,6 +37,7 @@ import { } from './text.js'; import { TONE } from './theme.js'; import { statusLineParts, type StatusLineField, type StatusLinePiece } from '../status-line.js'; +import { formatThinkingWaitLine } from '../run-progress.js'; export const USER_MARK = '❯'; export const ANSWER_MARK = '⏺'; @@ -185,11 +186,12 @@ export const READONLY_PREVIEW_TOOLS = new Set([ 'device_robotics_status', ]); -/** Verbs rotate slowly so a long run still looks alive without being cute. */ -const VERBS = ['Working', 'Thinking', 'Probing', 'Checking', 'Wiring', 'Verifying']; - -export function runVerb(seed: number): string { - return tui(VERBS[Math.abs(Math.trunc(seed / 3)) % VERBS.length] ?? 'Working'); +/** + * O99: no rotating slogan list — fake verbs do not count as progress. + * Prefer a real tool line; otherwise a stable working label (elapsed Ns is separate). + */ +export function runVerb(_seed: number): string { + return tui('Working'); } export function spinnerFrame(elapsedMs: number): string { @@ -943,15 +945,33 @@ export function renderLive(view: LiveView, width: number, verbose = false): TuiL const tokens = view.tokensOut > 0 ? tui(' · {count} out', { count: formatCompactCount(view.tokensOut) }) : ''; const queued = view.queued > 0 ? tui(' · {count} queued', { count: view.queued }) : ''; - const verb = view.waitingForDevice - ? tui('Waiting for device') - : view.thinkingActive && !view.streaming.trim() - ? tui('Thinking') - : runVerb(seconds); + // O99: real progress first — active tool label, then thinking-wait with Ns, + // then a stable Working label. Never rotate empty slogans. + let verb: string; + if (view.waitingForDevice) { + verb = tui('Waiting for device'); + } else if (view.toolLine && view.toolLine.trim()) { + verb = view.toolLine.trim(); + } else if (view.thinkingActive && !view.streaming.trim() && elapsedMs >= 30_000) { + verb = formatThinkingWaitLine(elapsedMs, isTuiZh()); + } else if (view.thinkingActive && !view.streaming.trim()) { + verb = tui('Thinking'); + } else if (elapsedMs >= 60_000 && !view.streaming.trim()) { + verb = formatThinkingWaitLine(elapsedMs, isTuiZh()); + } else { + verb = runVerb(seconds); + } + const showEllipsis = !view.toolLine && !verb.includes('等待') && !verb.includes('waited'); out.push( - line(clip(`${spinnerFrame(elapsedMs)} ${verb}… ${seconds}s${tokens}${queued}`, width), { - color: TONE.warn, - }) + line( + clip( + `${spinnerFrame(elapsedMs)} ${verb}${showEllipsis ? '…' : ''} ${seconds}s${tokens}${queued}`, + width + ), + { + color: TONE.warn, + } + ) ); // Silence is information too: past the hint threshold the spinner stops // pretending the model is thinking and says the stream has gone quiet (a diff --git a/src/core/agent/moss-agent-loop-adapter.ts b/src/core/agent/moss-agent-loop-adapter.ts index efde5083..c58a8abe 100644 --- a/src/core/agent/moss-agent-loop-adapter.ts +++ b/src/core/agent/moss-agent-loop-adapter.ts @@ -128,6 +128,15 @@ export function createMossAgentLoopEventAdapter( }, ]; } + case 'tool_execution_progress': + return [ + { + type: 'tool_progress', + toolCallId: event.toolCallId, + toolName: event.toolName, + elapsedSec: event.elapsed_sec, + }, + ]; case 'tool_execution_end': { const content = event.content ?? event.result; toolResults.push({ diff --git a/src/core/agent/moss-agent-types.ts b/src/core/agent/moss-agent-types.ts index bd8a47db..1a128a74 100644 --- a/src/core/agent/moss-agent-types.ts +++ b/src/core/agent/moss-agent-types.ts @@ -330,6 +330,12 @@ export type MossAgentEvent = | { type: 'text_delta'; delta: string } | { type: 'thinking_delta'; delta: string } | { type: 'tool_start'; toolName: string; toolCallId: string; input: Record } + | { + type: 'tool_progress'; + toolName: string; + toolCallId: string; + elapsedSec: number; + } | { type: 'tool_end'; toolName: string; diff --git a/test/cli-output.spec.mjs b/test/cli-output.spec.mjs index f64da310..26f5e973 100644 --- a/test/cli-output.spec.mjs +++ b/test/cli-output.spec.mjs @@ -92,9 +92,9 @@ console.log('[PASS] CLI output formatting'); // ─── createCliRunRenderer — oneshot turn_start noise ─────────────────────── // Regression: oneshot/headless mode used to print "- thinking turn 1" on // EVERY turn (including the first), exposing internal turn jargon and -// cluttering one-shot output. Now turn 1 and turn 2 are silent (a single -// tool call takes 2 turns — no need to announce), and only turn > 2 prints -// a brief "working…" so a multi-step tool loop shows progress. +// cluttering one-shot output. O99: turn_start itself stays silent — empty +// "working…" slogans do not count as progress; the run-progress heartbeat +// emits a real thinking-wait line after 30s of silence instead. { function makeRenderer(detailMode, interactive) { @@ -123,16 +123,14 @@ console.log('[PASS] CLI output formatting'); assert.equal(text(), '', 'oneshot turn 2 is silent (single-tool-call flow)'); } - // oneshot: turn > 2 prints a brief progress line. + // oneshot: turn > 2 is also silent on turn_start (O99 — no empty slogans). { const { renderer, text } = makeRenderer('progress', false); renderer.handle({ type: 'turn_start', turn: 3 }); const out = text(); - assert.ok(out.includes('working'), 'oneshot turn 3 uses friendly "working…" wording'); - assert.ok( - !/thinking turn/.test(out), - 'oneshot turn 3 does NOT use the old "thinking turn" jargon' - ); + assert.equal(out, '', 'oneshot turn 3 writes nothing on turn_start (O99)'); + assert.ok(!/working…|thinking turn/.test(out), 'no empty working… / thinking-turn jargon'); + renderer.dispose?.(); } // quiet mode: never prints turn announcements. diff --git a/test/o99-progress.spec.mjs b/test/o99-progress.spec.mjs new file mode 100644 index 00000000..1c127062 --- /dev/null +++ b/test/o99-progress.spec.mjs @@ -0,0 +1,318 @@ +#!/usr/bin/env node +/** + * O99 — long-run progress (stderr / TUI). + * Red/green: revert src/ → new behaviors fail; pure formatters / print guard stay green. + */ +import assert from 'node:assert/strict'; +import { test } from 'node:test'; +import { createRequire } from 'node:module'; + +const require = createRequire(import.meta.url); +const progress = () => require('../dist/cli/run-progress.js'); +const output = () => require('../dist/cli/output.js'); +const print = () => require('../dist/cli/print.js'); + +function fakeClock(start = 0) { + let now = start; + /** @type {Array<{ fire: () => void }>} */ + const timers = []; + return { + now: () => now, + setInterval(handler, _ms) { + const entry = { fire: handler }; + timers.push(entry); + return { + clear() { + const i = timers.indexOf(entry); + if (i >= 0) timers.splice(i, 1); + }, + }; + }, + advance(ms) { + now += ms; + for (const t of [...timers]) t.fire(); + }, + }; +} + +test('formatter: thinking-wait buckets 30/60/90 and has no empty slogans', () => { + const { formatThinkingWaitLine, thinkingWaitSeconds } = progress(); + assert.equal(thinkingWaitSeconds(29_999), 30); + assert.equal(thinkingWaitSeconds(30_000), 30); + assert.equal(thinkingWaitSeconds(60_000), 60); + assert.equal(thinkingWaitSeconds(90_000), 90); + assert.equal(formatThinkingWaitLine(30_000, false), 'Still reasoning, waited 30s'); + assert.equal(formatThinkingWaitLine(60_000, true), '正在推理，已等待 60s'); + assert.ok(!/working|thinking…/i.test(formatThinkingWaitLine(30_000, false))); +}); + +test('formatter: tool start/running include real tool+target (en+zh)', () => { + const { formatToolStartLine, formatToolRunningLine } = progress(); + const startEn = formatToolStartLine('edit_file', { path: 'src/hooks.ts' }, false); + assert.ok(startEn.includes('edit_file') && startEn.includes('hooks.ts')); + const startZh = formatToolStartLine('edit_file', { path: 'src/hooks.ts' }, true); + assert.ok(startZh.includes('正在调用') && startZh.includes('hooks.ts')); + const runEn = formatToolRunningLine('exec', { command: 'npm run check' }, 90, false); + assert.ok(runEn.includes('npm run check') && runEn.includes('90s')); +}); + +test('formatter: unfinished reason for max_turns (O98 alignment)', () => { + const { unfinishedReasonFromStop, formatUnfinishedLine } = progress(); + assert.ok(unfinishedReasonFromStop('max_turns_reached', false)); + assert.ok(formatUnfinishedLine('hit the turn limit', false).startsWith('Unfinished:')); + assert.ok(formatUnfinishedLine('已到回合上限', true).startsWith('未完成：')); +}); + +test('tracker: ≥90s silence emits thinking-wait at least every 60s (en)', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(1_000); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: false, + emitToolBoundaries: true, + clock, + }); + tracker.onEvent({ type: 'turn_start', turn: 1 }); + for (let i = 0; i < 18; i++) clock.advance(5_000); + tracker.dispose(); + const waits = lines.filter((l) => /Still reasoning, waited (\d+)s/.test(l)); + assert.ok(waits.length >= 2, `expected ≥2 wait lines, got ${JSON.stringify(lines)}`); + assert.ok(lines.every((l) => !/^(working|thinking)…?$/i.test(l.trim()))); +}); + +test('tracker: zh thinking-wait wording', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(0); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: true, + emitToolBoundaries: false, + clock, + }); + tracker.onEvent({ type: 'turn_start', turn: 1 }); + for (let i = 0; i < 8; i++) clock.advance(5_000); + tracker.dispose(); + assert.ok( + lines.some((l) => l.includes('正在推理，已等待')), + JSON.stringify(lines) + ); +}); + +test('tracker: tool_progress line names the command (not a slogan)', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(0); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: false, + emitToolBoundaries: true, + clock, + }); + tracker.onEvent({ + type: 'tool_start', + toolName: 'exec', + toolCallId: 'c1', + input: { command: 'npm test' }, + }); + tracker.onEvent({ + type: 'tool_progress', + toolName: 'exec', + toolCallId: 'c1', + elapsedSec: 60, + }); + tracker.dispose(); + assert.ok( + lines.some((l) => l.includes('npm test') && l.includes('60s')), + JSON.stringify(lines) + ); +}); + +test('tracker: unfinished last line on max_turns_reached', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(0); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: false, + emitToolBoundaries: true, + clock, + }); + tracker.onEvent({ + type: 'done', + result: { + response: 'partial', + toolCalls: [], + toolResults: [], + stopReason: 'max_turns_reached', + }, + }); + tracker.dispose(); + assert.ok( + lines.some((l) => /^Unfinished:/.test(l)), + JSON.stringify(lines) + ); +}); + +test('tracker: identical progress does not stack ≥3 times', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(0); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: false, + emitToolBoundaries: true, + clock, + }); + for (let i = 0; i < 5; i++) { + tracker.onEvent({ + type: 'tool_progress', + toolName: 'exec', + toolCallId: 'c1', + elapsedSec: 30, + }); + } + tracker.dispose(); + let run = 1; + let maxRun = 1; + for (let i = 1; i < lines.length; i++) { + if (lines[i] === lines[i - 1]) run++; + else run = 1; + maxRun = Math.max(maxRun, run); + } + assert.ok(maxRun < 3, `stacked ${maxRun}: ${JSON.stringify(lines)}`); +}); + +test('renderer: tool progress on stderr; final answer only on stdout', () => { + const { createCliRunRenderer } = output(); + const stderrChunks = []; + const stdoutChunks = []; + const renderer = createCliRunRenderer({ + detailMode: 'progress', + interactive: false, + stderr: { write: (s) => stderrChunks.push(String(s)), isTTY: false }, + stdout: { write: (s) => stdoutChunks.push(String(s)), isTTY: false }, + }); + renderer.handle({ type: 'turn_start', turn: 1 }); + renderer.handle({ + type: 'tool_start', + toolName: 'read_file', + toolCallId: 't1', + input: { path: 'src/cli/hooks.ts' }, + }); + renderer.handle({ + type: 'tool_progress', + toolName: 'read_file', + toolCallId: 't1', + elapsedSec: 45, + }); + renderer.handle({ + type: 'tool_end', + toolName: 'read_file', + toolCallId: 't1', + result: 'ok', + isError: false, + }); + renderer.handle({ type: 'text_delta', delta: 'FINAL_ANSWER_ONLY' }); + renderer.handle({ + type: 'done', + result: { + response: 'FINAL_ANSWER_ONLY', + toolCalls: [], + toolResults: [], + stopReason: 'end_turn', + }, + }); + renderer.dispose(); + const stderrText = stderrChunks.join(''); + const stdoutText = stdoutChunks.join(''); + assert.ok(stdoutText.includes('FINAL_ANSWER_ONLY')); + assert.ok(!stderrText.includes('FINAL_ANSWER_ONLY')); + assert.ok(/read_file|hooks\.ts/.test(stderrText), 'tool start should appear on stderr'); + // Must include the O99 tool_progress line (goes red if wiring/module missing). + assert.ok( + /Running read_file|正在跑 read_file|45s/.test(stderrText), + `expected tool_progress elapsed line on stderr, got: ${stderrText.slice(0, 400)}` + ); +}); + +test('renderer: unfinished stopReason prints clear last-line reason', () => { + const { createCliRunRenderer } = output(); + const stderrChunks = []; + const renderer = createCliRunRenderer({ + detailMode: 'progress', + interactive: false, + stderr: { write: (s) => stderrChunks.push(String(s)), isTTY: false }, + stdout: { write: () => {}, isTTY: false }, + }); + renderer.handle({ + type: 'done', + result: { + response: 'halfway', + toolCalls: [], + toolResults: [], + stopReason: 'max_turns_reached', + }, + }); + renderer.dispose(); + assert.ok(/Unfinished:|未完成：/.test(stderrChunks.join('')), stderrChunks.join('')); +}); + +test('short-task guard: ≤10s run emits ≤3 tracker progress lines', () => { + const { createRunProgressTracker } = progress(); + const lines = []; + const clock = fakeClock(0); + const tracker = createRunProgressTracker({ + sink: { write: (l) => lines.push(l) }, + zh: false, + emitToolBoundaries: true, + clock, + }); + tracker.onEvent({ type: 'turn_start', turn: 1 }); + tracker.onEvent({ + type: 'tool_start', + toolName: 'write_file', + toolCallId: 'c1', + input: { path: 'calc.py' }, + }); + clock.advance(2_000); + tracker.onEvent({ + type: 'tool_end', + toolName: 'write_file', + toolCallId: 'c1', + result: 'ok', + isError: false, + }); + tracker.onEvent({ type: 'text_delta', delta: 'done' }); + clock.advance(3_000); + tracker.onEvent({ + type: 'done', + result: { response: 'done', toolCalls: [], toolResults: [], stopReason: 'end_turn' }, + }); + tracker.dispose(); + assert.ok(lines.length <= 3, `got ${lines.length}: ${JSON.stringify(lines)}`); +}); + +test('print.ts: tool_progress yields no stdout stream-json events', () => { + // New behavior: explicit empty array (main returned undefined for unknown types). + const state = print().createHeadlessPrintState({ + sessionId: 's1', + model: 'm', + startTime: Date.now(), + }); + const events = print().formatHeadlessStreamEvent(state, { + type: 'tool_progress', + toolName: 'exec', + toolCallId: 'c1', + elapsedSec: 30, + }); + assert.ok(Array.isArray(events), 'must return an array, not undefined'); + assert.equal(events.length, 0); +}); + +test('guard: default CLI detail mode is still progress (main-green)', () => { + // Exists on main; must stay green after reverting O99 src. + const { resolveCliDetailMode } = output(); + assert.equal(resolveCliDetailMode([], {}), 'progress'); +}); From 0e3ef243bcfb3ff268a7c7ad1a68c6deee230f6d Mon Sep 17 00:00:00 2001 From: QiaolongLi1201 Date: Mon, 12 Oct 2026 01:32:31 +0800 Subject: [PATCH 2/2] test(O99): expect real tool progress in TUI live spinner MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Live spinner now shows the in-flight tool summary instead of Working…. Update tui-run-state and tui-shell assertions; narrow panes may clip token/queue tails after the tool line. --- test/tui-run-state.spec.mjs | 7 ++++--- test/tui-shell.spec.mjs | 11 +++++++---- 2 files changed, 11 insertions(+), 7 deletions(-) diff --git a/test/tui-run-state.spec.mjs b/test/tui-run-state.spec.mjs index 3dab95f1..42395ee4 100644 --- a/test/tui-run-state.spec.mjs +++ b/test/tui-run-state.spec.mjs @@ -149,12 +149,13 @@ const THINKING = 'The user wants one word. '; 80 ); const joined = text(lines); - assert.match(joined, /[✢✳✶✻✽] \w+… 4s/, 'spinner + elapsed seconds are shown'); + // O99: live spinner shows the real in-flight tool (not an empty Working… slogan). + assert.match(joined, /[✢✳✶✻✽] .+ 4s/, 'spinner + real progress + elapsed seconds are shown'); assert.ok(joined.includes('1.5k out'), 'current run output tokens are labeled'); assert.ok(joined.includes('1 queued'), 'queued submissions are shown'); assert.ok( - !joined.includes('fps_probe.sh'), - 'live region does not duplicate the transcript tool row' + joined.includes('fps_probe.sh'), + 'live spinner carries the in-flight tool summary (O99 progress)' ); assert.equal( store.rows.filter((row) => row.kind === 'tool' && row.text.includes('fps_probe.sh')).length, diff --git a/test/tui-shell.spec.mjs b/test/tui-shell.spec.mjs index 32732ef5..b0126d4b 100644 --- a/test/tui-shell.spec.mjs +++ b/test/tui-shell.spec.mjs @@ -339,17 +339,20 @@ for (const width of [40, 80, 120]) { width ); const liveText = text(live); - assert.match(liveText, /[✢✳✶✻✽] \w+… 4s/, `live@${width} shows a spinner and elapsed seconds`); - assert.ok(liveText.includes('1.2k out'), `live@${width} labels current output tokens`); + // O99: live spinner shows the real in-flight tool (not an empty Working… slogan). + assert.match(liveText, /[✢✳✶✻✽] .+ 4s/, `live@${width} shows spinner + real progress + elapsed`); assert.ok( - !liveText.includes('fps_probe.sh'), - `live@${width} does not duplicate the transcript tool` + liveText.includes('fps_probe.sh'), + `live@${width} carries the in-flight tool summary (O99 progress)` ); assert.ok(liveText.includes('camera_fps is 31.5'), `live@${width} previews the answer`); assertFits(live, width, `live@${width}`); if (width >= 80) { + assert.ok(liveText.includes('1.2k out'), `live@${width} labels current output tokens`); assert.ok(liveText.includes('1 queued'), `live@${width} shows the queue`); } else { + // Narrow panes clip the tail (tokens/queue) after the real tool summary. + assert.ok(liveText.includes('1.2k'), `live@${width} still shows a compact token count`); assert.ok( cells(live[live.length - 1].text) <= width, 'a narrow activity line stays within the pane width'