diff --git a/docs/design/2026-07-14-silent-command-heartbeat.md b/docs/design/2026-07-14-silent-command-heartbeat.md new file mode 100644 index 0000000000..c496b5d89e --- /dev/null +++ b/docs/design/2026-07-14-silent-command-heartbeat.md @@ -0,0 +1,75 @@ +# Silent Command Heartbeat + +Date: 2026-07-14 +Status: implemented + +## Problem + +A foreground shell command that produces no output emits no events between spawn and settle. In interactive TUI use this is fine — the spinner keeps moving — but for headless consumers (ACP gateways such as DataAgent, `--output-format stream-json` pipelines) the session goes completely quiet for the full duration of the command. A gateway watching the event stream cannot distinguish "a 165-second SQL probe is still running" from "the execution chain died", so long-running silent commands are reported by users as the agent hanging. + +Production diagnosis of such a session (DataAgent session `77255d98`, 41-minute task, ~32 minutes spent inside tool waits) identified the missing liveness signal as one of three P0 reliability fixes, alongside shell timeout semantics (PR 1, separate change) and a todo stop-guard (PR 3). + +Reference implementation: Claude Code polls the output file every second and invokes its progress callback even when the content is empty, then surfaces throttled, minimal-payload `tool_progress` events to SDK consumers. Progress never enters model context. + +## Goals + +- While a foreground shell command is silent, periodically emit a structured liveness signal to consumers that need it (ACP clients, stream-json). +- Carry stats only — elapsed time, output age, line/byte counts, effective timeout. Never command output. +- Never enter model context; never disturb the live-output display of interactive consumers. + +## Non-goals + +- Timeout auto-backgrounding (tracked separately as a P1 item). +- Streaming live command output to ACP clients (`content` frames). +- Forwarding MCP `mcp_tool_progress` over ACP, propagating subagent heartbeats into `AgentResultDisplay`, or TUI display enhancements — all follow-ups. + +## Design + +### Event shape + +`ShellProgressData` joins the `ToolResultDisplay` union in `packages/core/src/tools/tools.ts`, mirroring the existing `McpToolProgressData` precedent, with a shared exported guard `isShellProgressData`: + +```ts +interface ShellProgressData { + type: 'shell_progress'; + elapsedMs: number; // monotonic, since post-PTY-init spawn + lastOutputAgeMs?: number; // monotonic age of last output; absent = none yet + totalLines?: number; // PTY/AnsiOutput path only + totalBytes?: number; // PTY/AnsiOutput path only + timeoutMs?: number; // effective timeout incl. 120s default; absent when disabled +} +``` + +Durations are monotonic (`performance.now()` deltas) so NTP corrections cannot skew them; `lastOutputAgeMs` is an age rather than an epoch timestamp for the same reason. + +### Producer + +`ShellToolInvocation.execute()` starts a `setInterval` after the execution handle is obtained (so PTY dynamic-import time cannot produce a heartbeat for a process that does not exist) and only when an `updateOutput` callback is present. Each tick emits a heartbeat iff no display update has fired for a full interval — the check reuses the existing `lastUpdateTime` throttle state, so commands with flowing output never heartbeat. The timer is cleared in the same three places as the existing trailing-flush/timeout-warning timers: the service-throw catch, the result `finally`, and `onAbort` (after abort, a "still running" signal during the kill-to-settle window would be a lie). + +The interval comes from `tools.shell.heartbeatIntervalMs` (settings → CLI config → core `ConfigParameters` → `getShellHeartbeatIntervalMs()`, the same chain as `defaultTimeoutMs`), defaulting to 10 000 ms; `0` disables. + +### Consumers + +| Consumer | Behavior | +| -------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | +| `CoreToolScheduler` liveOutputCallback | Forwards heartbeats to `outputUpdateHandler` but skips the liveOutput replacement and update notification — a stats object must not blank the accumulated live view. | +| `useReactToolScheduler` (TUI) | Ignores heartbeats; the TUI already shows a spinner. | +| `agent-core` (subagent runtime) | Ignores heartbeats; broadcasting one would overwrite the subagent view's `liveOutputs`. | +| ACP `Session.runTool` | Passes an update callback into `invocation.execute()`. Heartbeats become fire-and-forget, meta-only `tool_call_update { status: 'in_progress', _meta: { toolName, shellProgress } }` frames. A `toolSettled` gate set the moment `execute()` returns (including throw) drops a tick racing the settle path, so the client can never observe `in_progress` after `completed`. Heartbeat count and last output age are recorded as `shell.heartbeat_count` / `shell.last_output_age_ms` span attributes on the existing tool-execution span. | +| stream-json | `createToolProgressHandler` forwards heartbeats through the existing `emitToolProgress` pipeline (`tool_progress` stream events, gated by `--include-partial-messages`). `ToolProgressStreamEvent.content` widens to `McpToolProgressData \| ShellProgressData`. | +| desktop `QwenAgent` | Skips `status: in_progress` updates in `handleToolCallUpdate` — it previously converted every `tool_call_update` into a terminal `tool_result`, which would have prematurely completed the command with an empty result on the first heartbeat. | +| channels `DaemonChannelBridge` | Drops kind-less `in_progress` frames instead of flagging them as malformed (`tool_call_update` there requires `kind`, which meta-only heartbeats do not carry). | +| web-shell daemon UI normalizer | Drops heartbeat frames — normalizing one would overwrite the tool block's human-readable title with the bare tool name derived from `_meta.toolName`. | + +ACP's `ToolCallUpdate` defines every field except the id as optional and `_meta` as the extensibility point, so protocol-conforming clients ignore the new frames. That contract is not self-enforcing, though: a full sweep of in-repo `tool_call_update` consumers found three that mishandled the frames (desktop agent, daemon channel bridge, web-shell normalizer — fixed above, each with a regression test), while the rest (VS Code companion, acp-bridge compaction, session export, daemon TUI adapter) merge conditionally and are heartbeat-safe as-is. On the permission-request path (which today emits no start notification), a heartbeat may be the first update a client sees for a tool call — same sequencing contract as the existing completed-only updates. + +### Why not ShellExecutionService + +The service would give marginally more accurate `lastOutputAt`, but the tool layer already observes every output event, and putting the timer there would have meant managing it across the PTY/child_process/promote lifecycles while PR 1 concurrently reworks the same file's pre-abort semantics. The user-facing `!` shell does not need heartbeats, so nothing is lost. + +## Verification + +- Unit: producer cadence/shape/cleanup (fake timers incl. `performance`), scheduler forwarding without liveOutput replacement, TUI hook retention, ACP meta-only frames + late-heartbeat gate, stream-json event shape and partial-messages gate. +- E2E stream-json: `sleep 15` produced `tool_progress` with `{type:'shell_progress', elapsedMs:10001, timeoutMs:30000}` and no output-stat fields. +- E2E ACP (stdio JSON-RPC): `tool_call` → heartbeat `tool_call_update` (meta-only, 10 s) → `completed`, with no trailing `in_progress`. +- TUI (tmux): silent command shows the normal spinner/elapsed row; no JSON leakage mid-run or in the final transcript. diff --git a/docs/users/configuration/settings.md b/docs/users/configuration/settings.md index d938e79ecb..e081284e23 100644 --- a/docs/users/configuration/settings.md +++ b/docs/users/configuration/settings.md @@ -320,6 +320,7 @@ If you are experiencing performance issues with file searching (e.g., with `@` c | `tools.sandboxImage` | string | Sandbox image URI used by Docker/Podman when `--sandbox-image` and `QWEN_SANDBOX_IMAGE` are not set. | `undefined` | | | `tools.shell.enableInteractiveShell` | boolean | Use `node-pty` for an interactive shell experience. Fallback to `child_process` still applies. | `true` | | | `tools.shell.defaultTimeoutMs` | number | Default timeout, in milliseconds, for foreground shell commands started by the agent. A per-call timeout on the shell tool overrides this. When unset, foreground commands time out after 120000 ms (2 minutes). Set to 0 to disable the timeout. | `undefined` | | +| `tools.shell.heartbeatIntervalMs` | number | Interval, in milliseconds, between liveness heartbeats emitted while a foreground shell command produces no output. Heartbeats are forwarded to ACP clients and stream-json consumers so they can tell a silent command from a dead session. When unset, heartbeats fire every 10000 ms (10 seconds). Set to 0 to disable heartbeats. | `undefined` | | | `tools.core` | array of strings | **Deprecated.** Will be removed in next version. Use `permissions.allow` + `permissions.deny` instead. Restricts built-in tools to an allowlist. All tools not in the list are disabled. | `undefined` | | | `tools.exclude` | array of strings | **Deprecated.** Use `permissions.deny` instead. Tool names to exclude from discovery. Automatically migrated to the `permissions` format on first load. | `undefined` | | | `tools.disabled` | array of strings | Tool names hidden from the registry entirely. Unlike `permissions.deny` (which blocks calls at runtime), disabled tools are never registered, so they do not appear in `/tools` and cannot be discovered or called by the model. For example, `["enter_plan_mode"]` prevents the model from switching into plan mode on its own. Merged as a union across scopes. | `undefined` | | diff --git a/packages/channels/base/src/DaemonChannelBridge.test.ts b/packages/channels/base/src/DaemonChannelBridge.test.ts index f66f6d5686..eff8c511d1 100644 --- a/packages/channels/base/src/DaemonChannelBridge.test.ts +++ b/packages/channels/base/src/DaemonChannelBridge.test.ts @@ -319,6 +319,116 @@ describe('DaemonChannelBridge', () => { bridge.stop(); }); + it('drops kind-less in_progress heartbeats without flagging the session as malformed', async () => { + const events = new EventQueue(); + const session = createFakeSession(events); + session.prompt.mockImplementation(async () => { + events.push({ + id: 1, + v: 1, + type: 'session_update', + data: { + sessionId: 'session-1', + update: { + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'in_progress', + _meta: { + toolName: 'run_shell_command', + shellProgress: { type: 'shell_progress', elapsedMs: 10_000 }, + }, + }, + }, + }); + events.push({ + id: 2, + v: 1, + type: 'session_update', + data: { + sessionId: 'session-1', + update: { + sessionUpdate: 'agent_message_chunk', + content: { type: 'text', text: 'Done.' }, + }, + }, + }); + events.push(turnCompleteEvent()); + return { stopReason: 'end_turn' }; + }); + const bridge = new DaemonChannelBridge({ + cwd: '/repo', + sessionFactory: vi.fn().mockResolvedValue(session), + }); + const errors: Error[] = []; + const toolCalls: unknown[] = []; + bridge.on('error', (err) => errors.push(err)); + bridge.on('toolCall', (event) => toolCalls.push(event)); + + await bridge.start(); + await bridge.newSession('/repo'); + + await expect(bridge.prompt('session-1', 'run it')).resolves.toBe('Done.'); + expect(errors).toHaveLength(0); + expect(toolCalls).toHaveLength(0); + + events.close(); + bridge.stop(); + }); + + it('flags a kind-less in_progress frame WITHOUT shellProgress as malformed', async () => { + // The heartbeat drop is scoped to frames carrying _meta.shellProgress, so + // a genuinely malformed kind-less tool_call still reaches emitProtocolError + // instead of being silently swallowed. + const events = new EventQueue(); + const session = createFakeSession(events); + session.prompt.mockImplementation(async () => { + events.push({ + id: 1, + v: 1, + type: 'session_update', + data: { + sessionId: 'session-1', + update: { + sessionUpdate: 'tool_call', + toolCallId: 'call-1', + status: 'in_progress', + _meta: { toolName: 'run_shell_command' }, + }, + }, + }); + events.push({ + id: 2, + v: 1, + type: 'session_update', + data: { + sessionId: 'session-1', + update: { + sessionUpdate: 'agent_message_chunk', + content: { type: 'text', text: 'Done.' }, + }, + }, + }); + events.push(turnCompleteEvent()); + return { stopReason: 'end_turn' }; + }); + const bridge = new DaemonChannelBridge({ + cwd: '/repo', + sessionFactory: vi.fn().mockResolvedValue(session), + }); + const errors: Error[] = []; + bridge.on('error', (err) => errors.push(err)); + + await bridge.start(); + await bridge.newSession('/repo'); + + await expect(bridge.prompt('session-1', 'run it')).resolves.toBe('Done.'); + expect(errors.length).toBeGreaterThan(0); + expect(errors[0].message).toContain('Malformed'); + + events.close(); + bridge.stop(); + }); + it('excludes nested subagent text from the daemon response', async () => { const events = new EventQueue(); const session = createFakeSession(events); diff --git a/packages/channels/base/src/DaemonChannelBridge.ts b/packages/channels/base/src/DaemonChannelBridge.ts index c0034feab8..dbcec0d3d1 100644 --- a/packages/channels/base/src/DaemonChannelBridge.ts +++ b/packages/channels/base/src/DaemonChannelBridge.ts @@ -671,6 +671,22 @@ export class DaemonChannelBridge case 'tool_call_update': { const toolCallId = getString(update['toolCallId']); const kind = getString(update['kind']); + const meta = isRecord(update['_meta']) ? update['_meta'] : undefined; + if ( + !kind && + toolCallId && + getString(update['status']) === 'in_progress' && + meta?.['shellProgress'] !== undefined + ) { + // Silent-shell liveness heartbeat: a kind-less in_progress frame + // carrying only the id, status, and _meta.shellProgress stats. + // Channels have no use for it — drop it without flagging the + // session as malformed. Gate on shellProgress (matching the + // qwen-agent and web-shell normalizer guards) so a genuinely + // malformed kind-less tool_call still reaches emitProtocolError + // below instead of being silently swallowed. + break; + } if (!toolCallId || !kind) { this.emitProtocolError(`Malformed daemon ${type} event`, update); break; diff --git a/packages/cli/src/acp-integration/session/Session.test.ts b/packages/cli/src/acp-integration/session/Session.test.ts index 2bad043012..140d1a2f91 100644 --- a/packages/cli/src/acp-integration/session/Session.test.ts +++ b/packages/cli/src/acp-integration/session/Session.test.ts @@ -4095,6 +4095,156 @@ describe('Session', () => { }); }); + describe('shell heartbeat forwarding', () => { + const runShellToolCall = async ( + execute: ReturnType, + ): Promise => { + const tool = { + name: 'run_shell_command', + kind: core.Kind.Execute, + build: vi.fn().mockReturnValue({ + params: { command: 'quiet-soak-test' }, + getDefaultPermission: vi.fn().mockResolvedValue('allow'), + getDescription: vi.fn().mockReturnValue('quiet-soak-test'), + toolLocations: vi.fn().mockReturnValue([]), + execute, + }), + }; + mockToolRegistry.getTool.mockReturnValue(tool); + mockConfig.getApprovalMode = vi.fn().mockReturnValue(ApprovalMode.YOLO); + + await ( + session as unknown as { + runToolCalls: ( + abortSignal: AbortSignal, + promptId: string, + calls: FunctionCall[], + loopState: { + totalToolCalls: number; + invalidToolParamErrors: Map; + loopDetected: boolean; + }, + ) => Promise; + } + ).runToolCalls( + new AbortController().signal, + 'prompt-heartbeat', + [{ id: 'shell_hb_1', name: 'run_shell_command', args: {} }], + { + totalToolCalls: 0, + invalidToolParamErrors: new Map(), + loopDetected: false, + }, + ); + }; + + const heartbeatUpdates = () => + vi + .mocked(mockClient.sessionUpdate) + .mock.calls.map(([params]) => params.update) + .filter( + (update) => + update.sessionUpdate === 'tool_call_update' && + update.status === 'in_progress' && + (update._meta as { shellProgress?: unknown } | undefined) + ?.shellProgress !== undefined, + ); + + it('forwards shell heartbeats as meta-only in_progress updates', async () => { + const heartbeat = { + type: 'shell_progress' as const, + elapsedMs: 10_000, + lastOutputAgeMs: 4_000, + timeoutMs: 120_000, + }; + const execute = vi.fn( + async ( + _signal: AbortSignal, + updateOutput?: (chunk: unknown) => void, + ) => { + updateOutput?.('plain live output'); + updateOutput?.(heartbeat); + return { llmContent: 'done', returnDisplay: 'done' }; + }, + ); + + await runShellToolCall(execute); + + const updates = heartbeatUpdates(); + expect(updates).toHaveLength(1); + expect(updates[0]).toMatchObject({ + sessionUpdate: 'tool_call_update', + toolCallId: 'shell_hb_1', + status: 'in_progress', + _meta: { + toolName: 'run_shell_command', + shellProgress: heartbeat, + }, + }); + // Meta-only: no content payload on heartbeat frames. + expect(updates[0]).not.toHaveProperty('content'); + }); + + it('drops heartbeats that land after the tool has settled', async () => { + let lateEmit: ((chunk: unknown) => void) | undefined; + const execute = vi.fn( + async ( + _signal: AbortSignal, + updateOutput?: (chunk: unknown) => void, + ) => { + lateEmit = updateOutput; + return { llmContent: 'done', returnDisplay: 'done' }; + }, + ); + + await runShellToolCall(execute); + expect(heartbeatUpdates()).toHaveLength(0); + + // A heartbeat tick racing the settle path must not regress the + // client-visible status back to in_progress. + lateEmit?.({ type: 'shell_progress', elapsedMs: 99_000 }); + expect(heartbeatUpdates()).toHaveLength(0); + }); + + it('records heartbeat counts on the tool-execution span', async () => { + const endSpanSpy = vi.spyOn(core, 'endToolExecutionSpan'); + const execute = vi.fn( + async ( + _signal: AbortSignal, + updateOutput?: (chunk: unknown) => void, + ) => { + updateOutput?.({ + type: 'shell_progress', + elapsedMs: 10_000, + lastOutputAgeMs: 10_000, + }); + updateOutput?.({ + type: 'shell_progress', + elapsedMs: 20_000, + lastOutputAgeMs: 20_000, + }); + return { llmContent: 'done', returnDisplay: 'done' }; + }, + ); + + await runShellToolCall(execute); + + const spanCall = endSpanSpy.mock.calls.find( + ([, meta]) => + (meta as { attributes?: Record } | undefined) + ?.attributes?.['shell.heartbeat_count'] !== undefined, + ); + expect(spanCall).toBeDefined(); + expect( + (spanCall![1] as { attributes: Record }).attributes, + ).toMatchObject({ + 'shell.heartbeat_count': 2, + 'shell.last_output_age_ms': 20_000, + }); + endSpanSpy.mockRestore(); + }); + }); + describe('tool outcome telemetry (#4602 review)', () => { it('records a soft tool failure (toolResult.error) as error, not success', async () => { const logToolCallSpy = vi diff --git a/packages/cli/src/acp-integration/session/Session.ts b/packages/cli/src/acp-integration/session/Session.ts index 8db40a97e1..b43251cde8 100644 --- a/packages/cli/src/acp-integration/session/Session.ts +++ b/packages/cli/src/acp-integration/session/Session.ts @@ -18,6 +18,8 @@ import type { GeminiChat, ToolCallConfirmationDetails, ToolResult, + ToolResultDisplay, + ShellProgressData, ChatRecord, HistoryGap, AgentEventEmitter, @@ -109,6 +111,7 @@ import { runInToolSpanContext, startToolExecutionSpan, endToolExecutionSpan, + isShellProgressData, logConversationFinishedEvent, ConversationFinishedEvent, logLoopDetected, @@ -5262,14 +5265,55 @@ export class Session implements SessionContext { const execSpan = startToolExecutionSpan(); let toolResult: ToolResult; + // Shell liveness heartbeats: forwarded to the client as meta-only + // tool_call_update frames so a headless gateway can tell a silent + // command from a dead session. `toolSettled` gates out a heartbeat + // tick that lands between the result settling and execute() + // returning — without it the client could see in_progress after + // completed and regress the tool call's status. + let toolSettled = false; + let heartbeatCount = 0; + let lastHeartbeat: ShellProgressData | undefined; + const onToolProgress = (chunk: ToolResultDisplay) => { + if (toolSettled || !isShellProgressData(chunk)) { + return; + } + heartbeatCount++; + lastHeartbeat = chunk; + void this.sendUpdate({ + sessionUpdate: 'tool_call_update', + toolCallId: callId, + status: 'in_progress', + _meta: { toolName, shellProgress: chunk }, + }).catch((err) => { + debugLogger.debug( + `[Session.runTool] heartbeat update failed for ${callId}: ${err}`, + ); + }); + }; + const heartbeatSpanAttributes = () => + heartbeatCount > 0 + ? { + attributes: { + 'shell.heartbeat_count': heartbeatCount, + ...(lastHeartbeat?.lastOutputAgeMs !== undefined && { + 'shell.last_output_age_ms': lastHeartbeat.lastOutputAgeMs, + }), + }, + } + : undefined; try { const sleepInhibitorHandle = acquireSleepInhibitor( this.config, `Qwen Code is executing tool ${toolName}`, ); try { - toolResult = await invocation.execute(activeToolAbortSignal); + toolResult = await invocation.execute( + activeToolAbortSignal, + onToolProgress, + ); } finally { + toolSettled = true; sleepInhibitorHandle.release(); } const aborted = activeToolAbortSignal.aborted; @@ -5281,6 +5325,7 @@ export class Session implements SessionContext { ? 'tool_error' : undefined, cancelled: aborted, + ...heartbeatSpanAttributes(), }); } catch (execError) { endToolExecutionSpan(execSpan, { @@ -5289,6 +5334,7 @@ export class Session implements SessionContext { ? 'tool_cancelled' : 'tool_exception', cancelled: activeToolAbortSignal.aborted, + ...heartbeatSpanAttributes(), }); throw execError; } diff --git a/packages/cli/src/config/config.ts b/packages/cli/src/config/config.ts index 18e3e2471f..0ae041ae56 100755 --- a/packages/cli/src/config/config.ts +++ b/packages/cli/src/config/config.ts @@ -2165,6 +2165,7 @@ export async function loadCliConfig( useBuiltinRipgrep: settings.tools?.useBuiltinRipgrep, shouldUseNodePtyShell: settings.tools?.shell?.enableInteractiveShell, shellDefaultTimeoutMs: settings.tools?.shell?.defaultTimeoutMs, + shellHeartbeatIntervalMs: settings.tools?.shell?.heartbeatIntervalMs, preventSystemSleep: settings.general?.preventSystemSleep ?? true, skipNextSpeakerCheck: settings.model?.skipNextSpeakerCheck, skipWorkflowUsageWarning: settings.model?.skipWorkflowUsageWarning ?? false, diff --git a/packages/cli/src/config/settingsSchema.ts b/packages/cli/src/config/settingsSchema.ts index a81ebbe822..d8f4a58ad7 100644 --- a/packages/cli/src/config/settingsSchema.ts +++ b/packages/cli/src/config/settingsSchema.ts @@ -2257,6 +2257,18 @@ const SETTINGS_SCHEMA = { 'Default timeout, in milliseconds, for foreground shell commands started by the agent. A per-call timeout on the shell tool overrides this. When unset, foreground commands time out after 120000 ms (2 minutes). Set to 0 to disable the timeout.', showInDialog: false, }, + heartbeatIntervalMs: { + type: 'integer', + minimum: 0, + maximum: 600000, + label: 'Silent Command Heartbeat Interval (ms)', + category: 'Tools', + requiresRestart: true, + default: undefined as number | undefined, + description: + 'Interval, in milliseconds, between liveness heartbeats emitted while a foreground shell command produces no output. Heartbeats are forwarded to ACP clients and stream-json consumers so they can tell a silent command from a dead session. When unset, heartbeats fire every 10000 ms (10 seconds). Set to 0 to disable heartbeats.', + showInDialog: false, + }, }, }, // Legacy tool permission fields – kept for backward compatibility. diff --git a/packages/cli/src/nonInteractive/io/BaseJsonOutputAdapter.ts b/packages/cli/src/nonInteractive/io/BaseJsonOutputAdapter.ts index 0d23f8a972..14b417f58e 100644 --- a/packages/cli/src/nonInteractive/io/BaseJsonOutputAdapter.ts +++ b/packages/cli/src/nonInteractive/io/BaseJsonOutputAdapter.ts @@ -13,6 +13,7 @@ import type { ServerGeminiStreamEvent, AgentResultDisplay, McpToolProgressData, + ShellProgressData, } from '@qwen-code/qwen-code-core'; import { GeminiEventType, @@ -96,11 +97,11 @@ export interface MessageEmitter { * In non-streaming mode, this is a no-op. * * @param request - Tool call request info - * @param progress - Structured MCP progress data + * @param progress - Structured MCP progress data or shell liveness heartbeat */ emitToolProgress( request: ToolCallRequestInfo, - progress: McpToolProgressData, + progress: McpToolProgressData | ShellProgressData, ): void; } @@ -1155,11 +1156,11 @@ export abstract class BaseJsonOutputAdapter { * to emit stream events when includePartialMessages is enabled. * * @param _request - Tool call request info - * @param _progress - Structured MCP progress data + * @param _progress - Structured MCP progress data or shell liveness heartbeat */ emitToolProgress( _request: ToolCallRequestInfo, - _progress: McpToolProgressData, + _progress: McpToolProgressData | ShellProgressData, ): void { // No-op in base class. Only StreamJsonOutputAdapter emits tool progress // as stream events when includePartialMessages is enabled. diff --git a/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.test.ts b/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.test.ts index 532cedb9a7..3738db3128 100644 --- a/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.test.ts +++ b/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.test.ts @@ -1036,6 +1036,41 @@ describe('StreamJsonOutputAdapter', () => { expect(stdoutWriteSpy).not.toHaveBeenCalled(); }); + it('should emit shell heartbeats as tool_progress stream events', () => { + adapter = new StreamJsonOutputAdapter(mockConfig, true); + stdoutWriteSpy.mockClear(); + + adapter.emitToolProgress( + { ...mockRequest, name: 'run_shell_command' }, + { + type: 'shell_progress', + elapsedMs: 10_000, + lastOutputAgeMs: 4_000, + totalLines: 12, + totalBytes: 512, + timeoutMs: 120_000, + }, + ); + + expect(stdoutWriteSpy).toHaveBeenCalledTimes(1); + const output = stdoutWriteSpy.mock.calls[0][0] as string; + const parsed = JSON.parse(output); + + expect(parsed.type).toBe('stream_event'); + expect(parsed.event).toEqual({ + type: 'tool_progress', + tool_use_id: 'tool-call-1', + content: { + type: 'shell_progress', + elapsedMs: 10_000, + lastOutputAgeMs: 4_000, + totalLines: 12, + totalBytes: 512, + timeoutMs: 120_000, + }, + }); + }); + it('should emit multiple tool_progress events for sequential progress updates', () => { adapter = new StreamJsonOutputAdapter(mockConfig, true); stdoutWriteSpy.mockClear(); diff --git a/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.ts b/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.ts index 5e9d803ce5..0613700880 100644 --- a/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.ts +++ b/packages/cli/src/nonInteractive/io/StreamJsonOutputAdapter.ts @@ -10,6 +10,7 @@ import type { ServerGeminiStreamEvent, ToolCallRequestInfo, McpToolProgressData, + ShellProgressData, } from '@qwen-code/qwen-code-core'; import { GeminiEventType } from '@qwen-code/qwen-code-core'; import type { @@ -310,7 +311,7 @@ export class StreamJsonOutputAdapter */ override emitToolProgress( request: ToolCallRequestInfo, - progress: McpToolProgressData, + progress: McpToolProgressData | ShellProgressData, ): void { if (!this.includePartialMessages) { return; diff --git a/packages/cli/src/nonInteractive/types.ts b/packages/cli/src/nonInteractive/types.ts index 7feb9fe7a1..6c7eb0d366 100644 --- a/packages/cli/src/nonInteractive/types.ts +++ b/packages/cli/src/nonInteractive/types.ts @@ -3,6 +3,7 @@ import type { ActiveGoal, SubagentConfig, McpToolProgressData, + ShellProgressData, } from '@qwen-code/qwen-code-core'; /** @@ -245,7 +246,7 @@ export interface MessageStopStreamEvent { export interface ToolProgressStreamEvent { type: 'tool_progress'; tool_use_id: string; - content: McpToolProgressData; + content: McpToolProgressData | ShellProgressData; } export interface ActiveGoalStreamEvent { diff --git a/packages/cli/src/ui/hooks/useReactToolScheduler.ts b/packages/cli/src/ui/hooks/useReactToolScheduler.ts index 74cc828710..856eb8a9a8 100644 --- a/packages/cli/src/ui/hooks/useReactToolScheduler.ts +++ b/packages/cli/src/ui/hooks/useReactToolScheduler.ts @@ -26,6 +26,7 @@ import { createDebugLogger, getToolResponseDisplayText, isAnyAutoMemPath, + isShellProgressData, } from '@qwen-code/qwen-code-core'; import * as path from 'node:path'; import { useCallback, useState, useMemo } from 'react'; @@ -114,6 +115,12 @@ export function useReactToolScheduler( const outputUpdateHandler: OutputUpdateHandler = useCallback( (toolCallId, outputChunk) => { + // Shell liveness heartbeats are for headless consumers; the TUI + // already shows a spinner and must not replace accumulated live + // output with a stats object. + if (isShellProgressData(outputChunk)) { + return; + } const compactOutput = compactToolResultDisplayForHistory(outputChunk); setToolCallsForDisplay((prevCalls) => prevCalls.map((tc) => { diff --git a/packages/cli/src/ui/hooks/useToolScheduler.test.ts b/packages/cli/src/ui/hooks/useToolScheduler.test.ts index ceb7814ec5..f3824001ad 100644 --- a/packages/cli/src/ui/hooks/useToolScheduler.test.ts +++ b/packages/cli/src/ui/hooks/useToolScheduler.test.ts @@ -193,6 +193,66 @@ describe('useReactToolScheduler in YOLO Mode', () => { }); expect(confirmationCall).toBeUndefined(); }); + + it('keeps shell heartbeats out of liveOutput while retaining display chunks', async () => { + let resolveExecute: (result: ToolResult) => void; + let emitUpdate: ((output: unknown) => void) | undefined; + const streamingTool = new MockTool({ + name: 'streamingTool', + displayName: 'Streaming Tool', + canUpdateOutput: true, + execute: vi.fn( + (_params: unknown, _signal?: AbortSignal, updateOutput?: unknown) => { + emitUpdate = updateOutput as (output: unknown) => void; + return new Promise((resolve) => { + resolveExecute = resolve; + }); + }, + ) as any, + }); + mockToolRegistry.getTool.mockReturnValue(streamingTool); + + const { result } = renderSchedulerInYoloMode(); + const schedule = result.current[1]; + + act(() => { + schedule( + { + callId: 'hbCall', + name: 'streamingTool', + args: {}, + } as any, + new AbortController().signal, + ); + }); + await act(async () => { + await vi.runAllTimersAsync(); + }); + await act(async () => { + await vi.runAllTimersAsync(); + }); + + act(() => { + emitUpdate!('streamed text'); + emitUpdate!({ type: 'shell_progress', elapsedMs: 10_000 }); + }); + + const executing = result.current[0].find( + (tc) => tc.request.callId === 'hbCall', + ) as { liveOutput?: unknown }; + // The display chunk is retained; the later heartbeat did not replace it. + expect(executing?.liveOutput).toBe('streamed text'); + + act(() => { + resolveExecute!({ + llmContent: 'done', + returnDisplay: 'done', + } as ToolResult); + }); + await act(async () => { + await vi.runAllTimersAsync(); + }); + }); }); describe('useReactToolScheduler', () => { diff --git a/packages/cli/src/utils/nonInteractiveHelpers.test.ts b/packages/cli/src/utils/nonInteractiveHelpers.test.ts index a0c17a762f..18d1758400 100644 --- a/packages/cli/src/utils/nonInteractiveHelpers.test.ts +++ b/packages/cli/src/utils/nonInteractiveHelpers.test.ts @@ -588,6 +588,28 @@ describe('createToolProgressHandler', () => { expect(mockAdapter.emitToolProgress).not.toHaveBeenCalled(); }); + it('should forward shell heartbeats as tool progress', () => { + const mockAdapter = { + emitToolProgress: vi.fn(), + } as unknown as JsonOutputAdapterInterface; + + const shellRequest = { ...mockRequest, name: 'run_shell_command' }; + const { handler } = createToolProgressHandler(shellRequest, mockAdapter); + + const heartbeat = { + type: 'shell_progress' as const, + elapsedMs: 10_000, + lastOutputAgeMs: 4_000, + timeoutMs: 120_000, + }; + handler('tool-call-1', heartbeat); + + expect(mockAdapter.emitToolProgress).toHaveBeenCalledWith( + shellRequest, + heartbeat, + ); + }); + it('should forward multiple progress updates', () => { const mockAdapter = { emitToolProgress: vi.fn(), diff --git a/packages/cli/src/utils/nonInteractiveHelpers.ts b/packages/cli/src/utils/nonInteractiveHelpers.ts index a7cc65d05d..dbcfbc232b 100644 --- a/packages/cli/src/utils/nonInteractiveHelpers.ts +++ b/packages/cli/src/utils/nonInteractiveHelpers.ts @@ -22,6 +22,7 @@ import { getArenaSystemReminder, getMCPServerStatus, getPlanModeSystemReminder, + isShellProgressData, } from '@qwen-code/qwen-code-core'; import type { Part, PartListUnion } from '@google/genai'; import type { @@ -272,9 +273,10 @@ function isMcpToolProgressData( /** * Creates a generic output update handler for tools with canUpdateOutput=true. - * This handler forwards MCP progress data (McpToolProgressData) as tool_progress - * stream events via the adapter. Progress events are only emitted when the adapter - * supports partial messages (i.e., includePartialMessages is true). + * This handler forwards MCP progress data (McpToolProgressData) and shell + * liveness heartbeats (ShellProgressData) as tool_progress stream events via + * the adapter. Progress events are only emitted when the adapter supports + * partial messages (i.e., includePartialMessages is true). * * @param request - Tool call request info * @param adapter - The adapter instance for emitting messages @@ -290,7 +292,7 @@ export function createToolProgressHandler( _callId: string, output: ToolResultDisplay, ) => { - if (isMcpToolProgressData(output)) { + if (isMcpToolProgressData(output) || isShellProgressData(output)) { adapter.emitToolProgress(request, output); } }; diff --git a/packages/core/src/agents/runtime/agent-core.ts b/packages/core/src/agents/runtime/agent-core.ts index ca1fbc0bca..b28eb43475 100644 --- a/packages/core/src/agents/runtime/agent-core.ts +++ b/packages/core/src/agents/runtime/agent-core.ts @@ -51,6 +51,7 @@ import type { ToolCallConfirmationDetails, ToolResultDisplay, } from '../../tools/tools.js'; +import { isShellProgressData } from '../../tools/tools.js'; import { getInitialChatHistory } from '../../utils/environmentContext.js'; import { FinishReason } from '@google/genai'; import type { @@ -1481,6 +1482,11 @@ export class AgentCore { const scheduler = new CoreToolScheduler({ config: this.runtimeContext, outputUpdateHandler: (callId, outputChunk) => { + // Shell liveness heartbeats have no subagent consumer; broadcasting + // one would overwrite the live output view kept in liveOutputs. + if (isShellProgressData(outputChunk)) { + return; + } this.eventEmitter?.emit(AgentEventType.TOOL_OUTPUT_UPDATE, { subagentId: this.subagentId, round: currentRound, diff --git a/packages/core/src/config/config.ts b/packages/core/src/config/config.ts index a99bdf5b66..959f221f28 100644 --- a/packages/core/src/config/config.ts +++ b/packages/core/src/config/config.ts @@ -1091,6 +1091,13 @@ export interface ConfigParameters { * getShellDefaultTimeoutMs. */ shellDefaultTimeoutMs?: number; + /** + * Interval, in ms, between liveness heartbeats emitted while a foreground + * shell command produces no output. 0 disables heartbeats; unset falls + * back to the shell tool's built-in default. See + * getShellHeartbeatIntervalMs. + */ + shellHeartbeatIntervalMs?: number; eventEmitter?: EventEmitter; output?: OutputSettings; inputFormat?: InputFormat; @@ -1786,6 +1793,7 @@ export class Config { private readonly truncateToolOutputLines: number; private readonly toolOutputBatchBudget: number; private readonly shellDefaultTimeoutMs: number | undefined; + private readonly shellHeartbeatIntervalMs: number | undefined; private readonly eventEmitter?: EventEmitter; private readonly channel: string | undefined; private readonly jsonFd: number | undefined; @@ -2062,6 +2070,16 @@ export class Config { params.shellDefaultTimeoutMs <= 2_147_483_647 ? params.shellDefaultTimeoutMs : undefined; + // Same timer-safety gate as shellDefaultTimeoutMs: the value reaches + // `setInterval`, which needs an integer in [0, 2^31-1]. 0 is valid and + // disables heartbeats. + this.shellHeartbeatIntervalMs = + params.shellHeartbeatIntervalMs !== undefined && + Number.isInteger(params.shellHeartbeatIntervalMs) && + params.shellHeartbeatIntervalMs >= 0 && + params.shellHeartbeatIntervalMs <= 2_147_483_647 + ? params.shellHeartbeatIntervalMs + : undefined; this.channel = params.channel; this.jsonFd = params.jsonFd; this.jsonFile = params.jsonFile; @@ -6034,6 +6052,15 @@ export class Config { return this.shellDefaultTimeoutMs; } + /** + * Configured interval (ms) between silent-command heartbeats, or + * `undefined` when unset (the shell tool falls back to its built-in + * default). 0 disables heartbeats. + */ + getShellHeartbeatIntervalMs(): number | undefined { + return this.shellHeartbeatIntervalMs; + } + getToolOutputBatchBudget(): number { if (this.toolOutputBatchBudget <= 0) { return Number.POSITIVE_INFINITY; diff --git a/packages/core/src/core/coreToolScheduler.test.ts b/packages/core/src/core/coreToolScheduler.test.ts index 78d6164ec9..df77e557f4 100644 --- a/packages/core/src/core/coreToolScheduler.test.ts +++ b/packages/core/src/core/coreToolScheduler.test.ts @@ -4764,6 +4764,152 @@ describe('CoreToolScheduler cancellation during executing with live output', () abortController.abort(); await schedulePromise; }); + + it('forwards shell heartbeats without replacing liveOutput', async () => { + class HeartbeatInvocation extends BaseToolInvocation< + { id: string }, + ToolResult + > { + getDescription(): string { + return `Heartbeat tool ${this.params.id}`; + } + + async execute( + signal: AbortSignal, + updateOutput?: (output: ToolResultDisplay) => void, + ): Promise { + updateOutput?.('real output'); + updateOutput?.({ type: 'shell_progress', elapsedMs: 10_000 }); + await new Promise((resolve) => { + if (signal.aborted) return resolve(); + const onAbort = () => { + signal.removeEventListener('abort', onAbort); + resolve(); + }; + signal.addEventListener('abort', onAbort, { once: true }); + }); + return { llmContent: 'done', returnDisplay: 'done' }; + } + } + + class HeartbeatTool extends BaseDeclarativeTool< + { id: string }, + ToolResult + > { + constructor() { + super( + 'heartbeat-tool', + 'Heartbeat Tool', + 'Emits a heartbeat and waits for abort', + Kind.Other, + { + type: 'object', + properties: { id: { type: 'string' } }, + required: ['id'], + }, + true, + true, + ); + } + protected createInvocation(params: { id: string }) { + return new HeartbeatInvocation(params); + } + } + + const tool = new HeartbeatTool(); + const mockToolRegistry = { + getTool: () => tool, + ensureTool: async () => tool, + getFunctionDeclarations: () => [], + tools: new Map(), + discovery: {}, + registerTool: () => {}, + getToolByName: () => tool, + getToolByDisplayName: () => tool, + getTools: () => [], + discoverTools: async () => {}, + getAllTools: () => [], + getToolsByServer: () => [], + } as unknown as ToolRegistry; + + const onAllToolCallsComplete = vi.fn(); + const onToolCallsUpdate = vi.fn(); + const outputUpdateHandler = vi.fn(); + const mockConfig = { + getSessionId: () => 'test-session-id', + getUsageStatisticsEnabled: () => true, + getDebugMode: () => false, + getApprovalMode: () => ApprovalMode.DEFAULT, + getContentGeneratorConfig: () => ({ + model: 'test-model', + authType: 'gemini', + }), + getToolRegistry: () => mockToolRegistry, + getShellExecutionConfig: () => ({ + terminalWidth: 90, + terminalHeight: 30, + }), + isInteractive: () => true, + getChatRecordingService: () => undefined, + getMessageBus: vi.fn().mockReturnValue(undefined), + getDisableAllHooks: vi.fn().mockReturnValue(true), + } as unknown as Config; + + const scheduler = new CoreToolScheduler({ + config: mockConfig, + outputUpdateHandler, + onAllToolCallsComplete, + onToolCallsUpdate, + getPreferredEditor: () => 'vscode', + onEditorClose: vi.fn(), + }); + + const abortController = new AbortController(); + const schedulePromise = scheduler.schedule( + [ + { + callId: '1', + name: 'heartbeat-tool', + args: { id: 'x' }, + isClientInitiated: true, + prompt_id: 'prompt-heartbeat', + }, + ], + abortController.signal, + ); + + await vi.waitFor(() => { + expect(outputUpdateHandler).toHaveBeenCalledTimes(2); + }); + + // Both the display chunk and the heartbeat reach the handler... + expect(outputUpdateHandler.mock.calls[0][1]).toBe('real output'); + expect(outputUpdateHandler.mock.calls[1][1]).toMatchObject({ + type: 'shell_progress', + elapsedMs: 10_000, + }); + + // ...but liveOutput only ever holds the display chunk. + const liveOutputs = onToolCallsUpdate.mock.calls + .map((call) => call[0][0] as ToolCall) + .filter( + (call): call is ExecutingToolCall => + call.status === 'executing' && call.liveOutput !== undefined, + ) + .map((call) => call.liveOutput); + expect(liveOutputs).toContain('real output'); + expect( + liveOutputs.some( + (out) => + typeof out === 'object' && + out !== null && + (out as { type?: string }).type === 'shell_progress', + ), + ).toBe(false); + + abortController.abort(); + await schedulePromise; + }); }); describe('CoreToolScheduler request queueing', () => { diff --git a/packages/core/src/core/coreToolScheduler.ts b/packages/core/src/core/coreToolScheduler.ts index bf62b8104d..0a432f124d 100644 --- a/packages/core/src/core/coreToolScheduler.ts +++ b/packages/core/src/core/coreToolScheduler.ts @@ -64,7 +64,7 @@ import { import { escapeSystemReminderTags } from '../utils/xml.js'; import { unescapePath, PATH_ARG_KEYS } from '../utils/paths.js'; import type { MemoryPressureMonitor } from '../services/memoryPressureMonitor.js'; -import { CONCURRENCY_SAFE_KINDS } from '../tools/tools.js'; +import { CONCURRENCY_SAFE_KINDS, isShellProgressData } from '../tools/tools.js'; import { isShellCommandReadOnly } from '../utils/shellReadOnlyChecker.js'; import { stripShellWrapper } from '../utils/shell-utils.js'; import { parsePositiveIntegerEnv } from '../utils/env.js'; @@ -3602,6 +3602,16 @@ export class CoreToolScheduler { const liveOutputCallback = scheduledCall.tool.canUpdateOutput ? (outputChunk: ToolResultDisplay) => { + if (isShellProgressData(outputChunk)) { + // Liveness heartbeat, not display content: forward to the + // outputUpdateHandler (stream-json progress events) but keep it + // out of liveOutput — replacing the accumulated command output + // with a stats object would blank the live view. + if (this.outputUpdateHandler) { + this.outputUpdateHandler(callId, outputChunk); + } + return; + } const compactOutput = this.compactResultDisplayForInteractiveHistory(outputChunk); if (this.outputUpdateHandler) { diff --git a/packages/core/src/telemetry/session-tracing.ts b/packages/core/src/telemetry/session-tracing.ts index 4a2977d37c..15197af940 100644 --- a/packages/core/src/telemetry/session-tracing.ts +++ b/packages/core/src/telemetry/session-tracing.ts @@ -954,6 +954,8 @@ export function endToolExecutionSpan( * user cancels. */ cancelled?: boolean; + /** Extra span attributes recorded verbatim alongside the standard set. */ + attributes?: Attributes; }, ): void { const spanId = getSpanId(span); @@ -970,7 +972,14 @@ export function endToolExecutionSpan( try { const duration = Date.now() - spanCtx.startTime; - const endAttributes: Attributes = { duration_ms: duration }; + // Apply caller-supplied attributes FIRST so the canonical keys written + // below (duration_ms, success, error) always win a key collision — a + // passthrough attribute must never mask the span's own outcome fields. + const endAttributes: Attributes = {}; + if (metadata?.attributes) { + Object.assign(endAttributes, metadata.attributes); + } + endAttributes['duration_ms'] = duration; if (metadata) { if (metadata.success !== undefined) diff --git a/packages/core/src/tools/shell.test.ts b/packages/core/src/tools/shell.test.ts index c2f2742aa5..b51acf889b 100644 --- a/packages/core/src/tools/shell.test.ts +++ b/packages/core/src/tools/shell.test.ts @@ -143,6 +143,7 @@ describe('ShellTool', () => { setApprovalMode: vi.fn(), getShouldUseNodePtyShell: vi.fn().mockReturnValue(false), getShellDefaultTimeoutMs: vi.fn().mockReturnValue(undefined), + getShellHeartbeatIntervalMs: vi.fn().mockReturnValue(undefined), getBackgroundShellRegistry: vi.fn().mockReturnValue({ register: vi.fn(), get: vi.fn(), @@ -1567,6 +1568,230 @@ describe('ShellTool', () => { ).toThrow('Directory must be an absolute path.'); }); + describe('Silent-command heartbeat', () => { + let updateOutputMock: Mock; + beforeEach(() => { + vi.useFakeTimers({ + toFake: [ + 'Date', + 'performance', + 'setTimeout', + 'clearTimeout', + 'setInterval', + 'clearInterval', + ], + }); + updateOutputMock = vi.fn(); + }); + afterEach(() => { + vi.useRealTimers(); + }); + + const heartbeats = () => + updateOutputMock.mock.calls + .map(([arg]) => arg) + .filter( + (arg) => + typeof arg === 'object' && + arg !== null && + (arg as { type?: string }).type === 'shell_progress', + ); + + const settle = async () => { + resolveExecutionPromise({ + rawOutput: Buffer.from(''), + output: '', + exitCode: 0, + signal: null, + error: null, + aborted: false, + pid: 12345, + executionMethod: 'child_process', + }); + }; + + it('emits a heartbeat per silent interval with elapsed and effective timeout', async () => { + const invocation = shellTool.build({ + command: 'quiet-soak-test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + // Let execute() reach the post-spawn heartbeat setup. + await vi.advanceTimersByTimeAsync(0); + + await vi.advanceTimersByTimeAsync(10_000); + expect(heartbeats()).toHaveLength(1); + await vi.advanceTimersByTimeAsync(10_000); + expect(heartbeats()).toHaveLength(2); + + const [first, second] = heartbeats() as Array>; + expect(first).toMatchObject({ + type: 'shell_progress', + elapsedMs: 10_000, + timeoutMs: 120_000, + }); + // No output yet → no lastOutputAgeMs, no stats. + expect(first).not.toHaveProperty('lastOutputAgeMs'); + expect(first).not.toHaveProperty('totalLines'); + expect(first).not.toHaveProperty('totalBytes'); + expect(second['elapsedMs']).toBe(20_000); + + await settle(); + await promise; + }); + + it('stays silent while output keeps the display fresh', async () => { + const invocation = shellTool.build({ + command: 'npm test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(0); + + for (let i = 0; i < 4; i++) { + await vi.advanceTimersByTimeAsync(5_000); + mockShellOutputCallback({ type: 'data', chunk: `line ${i}` }); + } + + expect(heartbeats()).toHaveLength(0); + + await settle(); + await promise; + }); + + it('reports lastOutputAgeMs once output has been seen', async () => { + const invocation = shellTool.build({ + command: 'npm test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(0); + + mockShellOutputCallback({ type: 'data', chunk: 'starting...' }); + await vi.advanceTimersByTimeAsync(20_000); + + const beats = heartbeats() as Array>; + expect(beats.length).toBeGreaterThan(0); + expect(beats.at(-1)!['lastOutputAgeMs']).toBe(20_000); + + await settle(); + await promise; + }); + + it('is disabled by heartbeatIntervalMs: 0', async () => { + (mockConfig.getShellHeartbeatIntervalMs as Mock).mockReturnValue(0); + const invocation = shellTool.build({ + command: 'quiet-soak-test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(30_000); + + expect(heartbeats()).toHaveLength(0); + + await settle(); + await promise; + }); + + it('honours a configured interval', async () => { + (mockConfig.getShellHeartbeatIntervalMs as Mock).mockReturnValue(5_000); + const invocation = shellTool.build({ + command: 'quiet-soak-test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(0); + + await vi.advanceTimersByTimeAsync(5_000); + expect(heartbeats()).toHaveLength(1); + + await settle(); + await promise; + }); + + it('stops on abort before the process settles', async () => { + const abortController = new AbortController(); + const invocation = shellTool.build({ + command: 'quiet-soak-test', + is_background: false, + }); + const promise = invocation.execute( + abortController.signal, + updateOutputMock, + ); + await vi.advanceTimersByTimeAsync(10_000); + expect(heartbeats()).toHaveLength(1); + + abortController.abort(); + await vi.advanceTimersByTimeAsync(30_000); + expect(heartbeats()).toHaveLength(1); + + resolveExecutionPromise({ + rawOutput: Buffer.from(''), + output: '', + exitCode: null, + signal: 15, + error: null, + aborted: true, + pid: 12345, + executionMethod: 'child_process', + }); + await promise; + }); + + it('stops once the command settles', async () => { + const invocation = shellTool.build({ + command: 'quiet-soak-test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(10_000); + expect(heartbeats()).toHaveLength(1); + + await settle(); + await promise; + + await vi.advanceTimersByTimeAsync(30_000); + expect(heartbeats()).toHaveLength(1); + }); + + it('carries output stats on the AnsiOutput path', async () => { + const invocation = shellTool.build({ + command: 'ansi-soak-test', + is_background: false, + }); + const promise = invocation.execute(mockAbortSignal, updateOutputMock); + await vi.advanceTimersByTimeAsync(0); + + const ansiChunk: import('../utils/terminalSerializer.js').AnsiOutput = [ + [ + { + text: 'hello', + bold: false, + italic: false, + dim: false, + underline: false, + inverse: false, + fg: '', + bg: '', + }, + ], + ]; + mockShellOutputCallback({ type: 'data', chunk: ansiChunk }); + await vi.advanceTimersByTimeAsync(20_000); + + const beats = heartbeats() as Array>; + expect(beats.length).toBeGreaterThan(0); + expect(beats.at(-1)).toMatchObject({ + totalLines: 1, + totalBytes: 5, + }); + + await settle(); + await promise; + }); + }); + describe('Streaming to `updateOutput`', () => { let updateOutputMock: Mock; beforeEach(() => { diff --git a/packages/core/src/tools/shell.ts b/packages/core/src/tools/shell.ts index 611766f52a..06337e05d1 100644 --- a/packages/core/src/tools/shell.ts +++ b/packages/core/src/tools/shell.ts @@ -917,6 +917,7 @@ export function parseNumstat(numstatOutput: string): Map { } export const OUTPUT_UPDATE_INTERVAL_MS = 1000; +export const DEFAULT_SHELL_HEARTBEAT_INTERVAL_MS = 10_000; const DEFAULT_FOREGROUND_TIMEOUT_MS = 120000; /** @@ -2180,6 +2181,8 @@ export class ShellToolInvocation extends BaseToolInvocation< let trailingFlushTimer: ReturnType | null = null; let timeoutWarningTimer: ReturnType | null = null; let showTimeoutWarning = false; + let heartbeatTimer: ReturnType | null = null; + let lastOutputPerfTime: number | null = null; const cancelTrailingFlush = () => { if (trailingFlushTimer !== null) { @@ -2195,6 +2198,13 @@ export class ShellToolInvocation extends BaseToolInvocation< } }; + const cancelHeartbeat = () => { + if (heartbeatTimer !== null) { + clearInterval(heartbeatTimer); + heartbeatTimer = null; + } + }; + const doUpdate = () => { // Any path that emits an update supersedes a pending trailing flush — // cancel centrally so leading-edge text, ANSI, binary_detected, and @@ -2223,9 +2233,12 @@ export class ShellToolInvocation extends BaseToolInvocation< // If the command is aborted (user cancel or timeout) while a trailing // flush is pending, cancel the timer so we don't emit a stale frame // between the abort signal firing and the result promise settling. + // The heartbeat stops here too: after abort, a "still running" signal + // during the kill-to-settle window would be a lie. const onAbort = () => { cancelTrailingFlush(); cancelTimeoutWarning(); + cancelHeartbeat(); }; combinedSignal.addEventListener('abort', onAbort, { once: true }); @@ -2262,6 +2275,7 @@ export class ShellToolInvocation extends BaseToolInvocation< switch (event.type) { case 'data': + lastOutputPerfTime = performance.now(); if (isBinaryStream) break; cumulativeOutput = event.chunk; // Stats are only consumed by the ANSI-output branch below, @@ -2308,6 +2322,7 @@ export class ShellToolInvocation extends BaseToolInvocation< shouldUpdate = true; break; case 'binary_progress': + lastOutputPerfTime = performance.now(); isBinaryStream = true; cumulativeOutput = `[Receiving binary output... ${formatMemoryUsage( event.bytesReceived, @@ -2415,6 +2430,7 @@ export class ShellToolInvocation extends BaseToolInvocation< // re-throw to the caller. cancelTrailingFlush(); cancelTimeoutWarning(); + cancelHeartbeat(); combinedSignal.removeEventListener('abort', onAbort); throw err; } @@ -2448,6 +2464,39 @@ export class ShellToolInvocation extends BaseToolInvocation< // difference matters here. const executionStartTime = performance.now(); + // Liveness heartbeat for silent commands: while no output has arrived + // for a full interval, emit a small structured ShellProgressData through + // the same updateOutput channel so headless consumers (ACP, stream-json) + // can distinguish "still running" from a dead execution chain. Display + // consumers ignore it. Both the idle gate and the reported durations use + // the monotonic `performance.now()` clock (via `lastOutputPerfTime`, + // falling back to spawn time before any output), so an NTP step can + // neither skew the payload nor misfire the heartbeat. Started only + // post-spawn so PTY init can't produce a heartbeat for a process that + // doesn't exist yet. + const heartbeatIntervalMs = + this.config.getShellHeartbeatIntervalMs() ?? + DEFAULT_SHELL_HEARTBEAT_INTERVAL_MS; + if (updateOutput && heartbeatIntervalMs > 0 && !combinedSignal.aborted) { + heartbeatTimer = setInterval(() => { + const now = performance.now(); + const idleSince = lastOutputPerfTime ?? executionStartTime; + if (now - idleSince < heartbeatIntervalMs) return; + updateOutput({ + type: 'shell_progress', + elapsedMs: Math.round(now - executionStartTime), + ...(lastOutputPerfTime !== null && { + lastOutputAgeMs: Math.round(now - lastOutputPerfTime), + }), + // Stats are only maintained on the PTY/AnsiOutput path; omit + // rather than report a misleading 0 on the plain-string path. + ...(totalLines > 0 && { totalLines }), + ...(totalBytes > 0 && { totalBytes }), + ...(effectiveTimeout > 0 && { timeoutMs: effectiveTimeout }), + }); + }, heartbeatIntervalMs); + } + let result; try { result = await resultPromise; @@ -2459,6 +2508,7 @@ export class ShellToolInvocation extends BaseToolInvocation< // happy path and the (theoretical) reject path so no timer leaks. cancelTrailingFlush(); cancelTimeoutWarning(); + cancelHeartbeat(); combinedSignal.removeEventListener('abort', onAbort); } diff --git a/packages/core/src/tools/tools.ts b/packages/core/src/tools/tools.ts index ed00bc874f..afb112be79 100644 --- a/packages/core/src/tools/tools.ts +++ b/packages/core/src/tools/tools.ts @@ -651,6 +651,39 @@ export interface McpToolProgressData { message?: string; } +/** + * Structured heartbeat for silent foreground shell commands, emitted through + * the updateOutput channel while no display update has fired for + * `tools.shell.heartbeatIntervalMs` (default 10s). Carries liveness stats + * only — never command output — and never enters model context. Consumers + * that render live output (TUI, subagent views) ignore it; the ACP session + * and stream-json adapters forward it so headless gateways can distinguish + * "still running" from a dead execution chain. + */ +export interface ShellProgressData { + type: 'shell_progress'; + /** Monotonic elapsed time since the process spawned (post-PTY-init), in ms. */ + elapsedMs: number; + /** Monotonic age of the last output chunk, in ms; absent = no output yet. */ + lastOutputAgeMs?: number; + /** Cumulative output stats; only present on the PTY/AnsiOutput path. */ + totalLines?: number; + totalBytes?: number; + /** Effective timeout governing this command (including the 120s default); absent when disabled. */ + timeoutMs?: number; +} + +export function isShellProgressData( + display: unknown, +): display is ShellProgressData { + return ( + typeof display === 'object' && + display !== null && + 'type' in display && + (display as ShellProgressData).type === 'shell_progress' + ); +} + export type ToolResultDisplay = | string | FileDiff @@ -660,7 +693,8 @@ export type ToolResultDisplay = | TeamResultDisplay | TaskListResultDisplay | AnsiOutputDisplay - | McpToolProgressData; + | McpToolProgressData + | ShellProgressData; export interface TeamResultDisplay { type: 'team_result'; diff --git a/packages/desktop/packages/shared/src/agent/__tests__/qwen-agent-tool-updates.test.ts b/packages/desktop/packages/shared/src/agent/__tests__/qwen-agent-tool-updates.test.ts new file mode 100644 index 0000000000..16310e220c --- /dev/null +++ b/packages/desktop/packages/shared/src/agent/__tests__/qwen-agent-tool-updates.test.ts @@ -0,0 +1,106 @@ +import { describe, expect, it } from 'bun:test'; +import { mkdtempSync } from 'node:fs'; +import { join } from 'node:path'; +import { tmpdir } from 'node:os'; +import { QwenAgent } from '../qwen-agent.ts'; + +type BackendConfig = ConstructorParameters[0]; + +type QwenToolUpdateInternals = { + handleToolCallUpdate: (update: Record) => void; + eventQueue: { + drain: () => AsyncIterator<{ type: string; [key: string]: unknown }>; + }; +}; + +function createAgent(cwd: string): QwenAgent { + return new QwenAgent({ + provider: 'qwen', + workspace: { + id: 'workspace-qwen', + name: 'Qwen Workspace', + slug: 'qwen-workspace', + rootPath: cwd, + createdAt: Date.now(), + }, + session: { + id: 'session-qwen', + name: 'Qwen Session', + workspaceRootPath: cwd, + createdAt: Date.now(), + lastUsedAt: Date.now(), + permissionMode: 'ask', + }, + isHeadless: true, + } as BackendConfig); +} + +describe('QwenAgent tool_call_update handling', () => { + it('ignores in_progress heartbeat frames and only emits tool_result on completion', async () => { + const cwd = mkdtempSync(join(tmpdir(), 'qwen-agent-tool-updates-')); + const agent = createAgent(cwd); + const internals = agent as unknown as QwenToolUpdateInternals; + + // A silent-shell liveness heartbeat: in_progress, meta-only. Converting + // it into a tool_result would prematurely complete the call. + internals.handleToolCallUpdate({ + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'in_progress', + _meta: { + toolName: 'run_shell_command', + shellProgress: { type: 'shell_progress', elapsedMs: 10_000 }, + }, + }); + + // The real terminal update still produces a tool_result. + internals.handleToolCallUpdate({ + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'completed', + content: [ + { type: 'content', content: { type: 'text', text: 'done' } }, + ], + _meta: { toolName: 'run_shell_command' }, + }); + + const iterator = internals.eventQueue.drain(); + const first = await iterator.next(); + await iterator.return?.(undefined); + + // The first (and only) queued event is the terminal result — the + // heartbeat produced nothing. Pin `result` to the completed frame's + // payload ('done'): a dropped guard would instead enqueue the heartbeat + // as the first tool_result with result 'Tool completed' (and isError + // false), so asserting only type + isError would stay green through the + // regression — the result assertion is what actually gates the guard. + expect(first.value?.type).toBe('tool_result'); + expect(first.value?.isError).toBe(false); + expect(first.value?.result).toBe('done'); + }); + + it('does not drop an in_progress frame that carries a kind', async () => { + const cwd = mkdtempSync(join(tmpdir(), 'qwen-agent-tool-updates-')); + const agent = createAgent(cwd); + const internals = agent as unknown as QwenToolUpdateInternals; + + // The drop guard is scoped to kind-less heartbeats (matching the + // web-shell normalizer): an in_progress frame WITH a kind is not a bare + // heartbeat and must still flow through to a tool_result. + internals.handleToolCallUpdate({ + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'in_progress', + kind: 'execute', + _meta: { + toolName: 'run_shell_command', + shellProgress: { type: 'shell_progress', elapsedMs: 10_000 }, + }, + }); + + const iterator = internals.eventQueue.drain(); + const first = await iterator.next(); + await iterator.return?.(undefined); + expect(first.value?.type).toBe('tool_result'); + }); +}); diff --git a/packages/desktop/packages/shared/src/agent/qwen-agent.ts b/packages/desktop/packages/shared/src/agent/qwen-agent.ts index af480061bb..220c85e17a 100644 --- a/packages/desktop/packages/shared/src/agent/qwen-agent.ts +++ b/packages/desktop/packages/shared/src/agent/qwen-agent.ts @@ -4625,9 +4625,23 @@ export class QwenAgent extends BaseAgent { } private handleToolCallUpdate(update: JsonRecord): void { + // Silent-shell liveness heartbeats arrive as in_progress frames with no + // kind, carrying _meta.shellProgress, while the tool is still running; + // converting one into a tool_result would prematurely complete the call + // with an empty result. Match the web-shell normalizer's predicate + // exactly — in_progress AND kind-absent AND shellProgress — so a + // kind-bearing frame is never dropped here while the normalizer forwards + // it (heartbeats emitted by the ACP session never carry a kind). + const meta = toRecord(update._meta); + if ( + asString(update.status) === 'in_progress' && + asString(update.kind) === undefined && + meta.shellProgress !== undefined + ) { + return; + } const toolUseId = asString(update.toolCallId) || `qwen-tool-${++this.toolIdCounter}`; - const meta = toRecord(update._meta); const toolName = this.toolNames.get(toolUseId) || normalizeToolName(asString(meta.toolName), asString(update.kind)); diff --git a/packages/sdk-typescript/src/daemon/ui/normalizer.ts b/packages/sdk-typescript/src/daemon/ui/normalizer.ts index 60e70af685..44271840e9 100644 --- a/packages/sdk-typescript/src/daemon/ui/normalizer.ts +++ b/packages/sdk-typescript/src/daemon/ui/normalizer.ts @@ -713,8 +713,21 @@ function normalizeSessionUpdate( ]; } case 'tool_call': - case 'tool_call_update': + case 'tool_call_update': { + // Silent-shell liveness heartbeat: a meta-only in_progress frame with + // no kind/title/content. Normalizing it would overwrite the tool + // block's human-readable title with the bare tool name from _meta; + // the web UI has its own activity indicator, so drop the frame. + const meta = isRecord(update['_meta']) ? update['_meta'] : undefined; + if ( + getString(update, 'status') === 'in_progress' && + getString(update, 'kind') === undefined && + meta?.['shellProgress'] !== undefined + ) { + return []; + } return [normalizeToolUpdate(update, base)]; + } case 'shell_output': case 'tool_output': { const text = getOutputText(update); diff --git a/packages/sdk-typescript/test/unit/daemonUi.test.ts b/packages/sdk-typescript/test/unit/daemonUi.test.ts index e1609091c0..47da26e8aa 100644 --- a/packages/sdk-typescript/test/unit/daemonUi.test.ts +++ b/packages/sdk-typescript/test/unit/daemonUi.test.ts @@ -64,6 +64,71 @@ describe('daemon UI normalizer and transcript reducer', () => { ]); }); + it('drops silent-shell heartbeat tool updates instead of rewriting the tool block', () => { + const events = normalizeDaemonEvent({ + id: 1, + v: 1, + type: 'session_update', + data: { + update: { + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'in_progress', + _meta: { + toolName: 'run_shell_command', + shellProgress: { type: 'shell_progress', elapsedMs: 10_000 }, + }, + }, + }, + }); + + expect(events).toEqual([]); + + // A real terminal update for the same call still normalizes. + const completed = normalizeDaemonEvent({ + id: 2, + v: 1, + type: 'session_update', + data: { + update: { + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'completed', + _meta: { toolName: 'run_shell_command' }, + }, + }, + }); + expect(completed).toMatchObject([ + { type: 'tool.update', toolCallId: 'call-1', status: 'completed' }, + ]); + }); + + it('normalizes an in_progress frame that carries a kind (the drop is scoped to kind-less heartbeats)', () => { + // The `kind === undefined` condition is load-bearing: an in_progress + // frame WITH a kind is not a bare heartbeat and must pass through to a + // tool.update, even if it also carries shellProgress. + const events = normalizeDaemonEvent({ + id: 1, + v: 1, + type: 'session_update', + data: { + update: { + sessionUpdate: 'tool_call_update', + toolCallId: 'call-1', + status: 'in_progress', + kind: 'execute', + _meta: { + toolName: 'run_shell_command', + shellProgress: { type: 'shell_progress', elapsedMs: 10_000 }, + }, + }, + }, + }); + expect(events).toMatchObject([ + { type: 'tool.update', toolCallId: 'call-1', status: 'in_progress' }, + ]); + }); + it('stores input annotations on locally appended user messages', () => { const store = createDaemonTranscriptStore(); const inputAnnotations = [ diff --git a/packages/vscode-ide-companion/schemas/settings.schema.json b/packages/vscode-ide-companion/schemas/settings.schema.json index 67d8f62c20..a44dd46a87 100644 --- a/packages/vscode-ide-companion/schemas/settings.schema.json +++ b/packages/vscode-ide-companion/schemas/settings.schema.json @@ -1040,6 +1040,12 @@ "type": "integer", "minimum": 0, "maximum": 600000 + }, + "heartbeatIntervalMs": { + "description": "Interval, in milliseconds, between liveness heartbeats emitted while a foreground shell command produces no output. Heartbeats are forwarded to ACP clients and stream-json consumers so they can tell a silent command from a dead session. When unset, heartbeats fire every 10000 ms (10 seconds). Set to 0 to disable heartbeats.", + "type": "integer", + "minimum": 0, + "maximum": 600000 } } },