diff --git a/src/backend/listener.ts b/src/backend/listener.ts index ba035cb..78cc4f3 100644 --- a/src/backend/listener.ts +++ b/src/backend/listener.ts @@ -95,7 +95,9 @@ export class EventStreamListener { const isTimeout = resp.error.message === "timeout"; if (!isTimeout || attempt === MAX_ATTEMPTS) { if (isTimeout) { - warn(`subscribe: all ${MAX_ATTEMPTS} attempts timed out (backend unresponsive for ~${Math.round((MAX_ATTEMPTS * 5000 + 500) / 1000)}s)`); + warn( + `subscribe: all ${MAX_ATTEMPTS} attempts timed out (backend unresponsive for ~${Math.round((MAX_ATTEMPTS * 5000 + 500) / 1000)}s)`, + ); } throw new Error(formatSubscribeError(resp)); } @@ -126,6 +128,15 @@ export class EventStreamListener { } } + /** + * True if events are queued waiting for a poll (non-destructive). Lets the + * turn loop check liveness without consuming an event — used by the stall + * reconciliation to confirm a turn is still alive before ending it. + */ + hasQueuedEvents(): boolean { + return this.queue.length > 0; + } + /** * Wait for the next event, resolving once one arrives or `timeoutMs` elapses * (resolves null on timeout). Events arriving with no active waiter are diff --git a/src/config/auto-compact.ts b/src/config/auto-compact.ts index 01ce1bf..3f6b1eb 100644 --- a/src/config/auto-compact.ts +++ b/src/config/auto-compact.ts @@ -40,35 +40,36 @@ export async function maybeAutoCompact( const threshold = autoCompactThreshold(); if (threshold <= 0) return; // disabled - // Read current context usage via session/read. - let used = 0; + const msgId = randomUUID(); try { - const backend = server.ensureBackend(); - const resp = await backend.request( - server.nextId(), - "session/read", - { sessionId: zcodeSid }, - 5000, - ); - if (resp.error) return; - const result = (resp.result ?? {}) as { projection?: { contextUsed?: number } }; - used = result.projection?.contextUsed ?? 0; - } catch (e) { - warn(`auto-compact: session/read failed (${e instanceof Error ? e.message : String(e)})`); - return; - } + // Read current context usage via session/read. + let used = 0; + try { + const backend = server.ensureBackend(); + const resp = await backend.request( + server.nextId(), + "session/read", + { sessionId: zcodeSid }, + 5000, + ); + if (resp.error) return; + const result = (resp.result ?? {}) as { projection?: { contextUsed?: number } }; + used = result.projection?.contextUsed ?? 0; + } catch (e) { + warn(`auto-compact: session/read failed (${e instanceof Error ? e.message : String(e)})`); + return; + } - if (used < threshold) return; + if (used < threshold) return; + + log(`auto-compact: contextUsed=${used} >= threshold=${threshold}, compacting…`); + await sendTextChunk( + cx, + acpSid, + `🔄 auto-compact: context usage ${used.toLocaleString()} ≥ threshold ${threshold.toLocaleString()}, compressing…`, + msgId, + ); - log(`auto-compact: contextUsed=${used} >= threshold=${threshold}, compacting…`); - const msgId = randomUUID(); - await sendTextChunk( - cx, - acpSid, - `🔄 auto-compact: context usage ${used.toLocaleString()} ≥ threshold ${threshold.toLocaleString()}, compressing…`, - msgId, - ); - try { // compact() handles: session/compact → waitForTurnIdle → emitInitialUsage. const result = (await compact(server, { sessionId: acpSid }, cx)) as { __lockTimeout?: boolean; diff --git a/src/handlers/dispatch.ts b/src/handlers/dispatch.ts index 9160b03..8209a8f 100644 --- a/src/handlers/dispatch.ts +++ b/src/handlers/dispatch.ts @@ -312,7 +312,11 @@ async function dispatchUsageDelta( // config.json limit.context so the editor can render the context bar. let size = ev.size; if (!size) { - const { providerId, modelId } = parseModelValue(await currentModelCached(server, acpSid)); + // Resolve to the real backend session id — `acpSid` may be a lazy + // session/new placeholder that the backend rejects with "Session is not + // active", wasting a 5s request timeout on every usage_update. + const zcodeSid = server.resolveSid(acpSid) ?? acpSid; + const { providerId, modelId } = parseModelValue(await currentModelCached(server, zcodeSid)); size = modelContextWindow(providerId, modelId); } await sendSessionUpdate(cx, acpSid, { diff --git a/src/handlers/session.ts b/src/handlers/session.ts index 23e08e4..4a70c79 100644 --- a/src/handlers/session.ts +++ b/src/handlers/session.ts @@ -600,9 +600,11 @@ export async function prompt( // returning so the next prompt has room. Configured via // ZCODE_ACP_AUTO_COMPACT_THRESHOLD (absolute token count; 0/unset = // disabled). Only on end_turn — cancelled/max_turn_requests skips - // compaction. Best-effort: failures are logged inside - // maybeAutoCompact, never thrown. - if (result.stopReason === "end_turn") { + // compaction, as does a stall-recovered end_turn (the completion was + // inferred by the stall heuristic, not confirmed by turn.completed — + // compressing an in-flight task's context would destroy the work). + // Best-effort: failures are logged inside maybeAutoCompact, never thrown. + if (result.stopReason === "end_turn" && !turn.stallRecovered) { const { maybeAutoCompact } = await import("../config/auto-compact.js"); await maybeAutoCompact(server, cx, params.sessionId, zcodeSid); } @@ -667,10 +669,24 @@ export async function setConfigOptionHandler( } /** - * `session/cancel` → mark the pending turn cancelled. The turn loop observes - * the flag and forwards `session/stop` itself (mirrors Python: cancel only - * sets the flag; stop is sent by `_run_event_turn`). Eagerly sending stop - * here would race with a turn that already completed. + * `session/cancel` → stop the in-flight turn immediately. Mirrors the ZCode + * App's stop button, which sends a stop command directly (there is no + * "cancel" concept on the client — only stop). + * + * We fire `session/stop` here instead of deferring it to the turn loop. The + * loop is blocked for seconds at a time behind awaits (handleServerRequests + * waiting on a permission popup; dispatchEvent running per-event; the + * tool-result path awaiting dispatchEditDiff/dispatchPlanIfChanged backend + * calls with up to 8s timeouts). A deferred stop only fires once the loop + * finishes whatever await it is stuck in, so the user's press of stop can lag + * by the full remaining await window — the turn visibly "keeps running". + * `session/stop` is fire-and-forget and fully idempotent (the backend no-ops + * on a session with no active turn, and on a turn already aborted), so firing + * it eagerly is safe; the loop's `stopSent` guard prevents a second send. + * + * `turn.cancelled` is still set so the turn loop switches to its silent-drain + * path (translate to detect turnDone, but discard every internal event — no + * text/tool/usage is pushed after the user stopped). */ export async function cancel( server: ZcodeAcpServer, @@ -678,10 +694,21 @@ export async function cancel( ): Promise { const zcodeSid = server.resolveSid(params.sessionId); if (!zcodeSid) return; + // Cancel ALL matching turns for this session (not just the first). During a + // preempt-wait, pendingTurns holds both the old turn (already cancelled by + // preempt) and the new queued prompt; breaking on the first match would + // leave the queued prompt running. The stopSent guard dedupes the backend + // stop call across turns and repeated cancels. for (const [, turn] of server.pendingTurns) { if (turn.zcodeSid === zcodeSid) { turn.cancelled = true; - break; // one turn per session at a time + if (!turn.stopSent) { + stopBackendTurn(server, zcodeSid); + turn.stopSent = true; + } + // Record cancel time so a prompt arriving in the backend's ~20s + // model-connection recovery window can fast-fail instead of hanging. + server.lastCancelledAt.set(zcodeSid, Date.now()); } } log(`session/cancel → ${zcodeSid}`); @@ -769,14 +796,17 @@ function withPreemptLock( * registered itself in pendingTurns), so a concurrent prompt entering its own * section is guaranteed to see this caller's turn and cancel it. * - * We do NOT fire stop here — the old turn's own loop detects turn.cancelled - * and fires stop itself (turn-loop cancel site), then keeps looping until the - * backend emits turn.completed/turn.failed. Since the turn loop now waits for - * that backend completion event before exiting, the pendingTurns cleanup in - * its finally block is the reliable "backend is done, lock released" signal. - * Waiting on pendingTurns deletion therefore blocks until the backend has - * truly finished — far more reliable than probing session/goal show (which - * times out during the backend's stop-finalization window). + * `session/stop` is fired here, immediately, for the same reason the cancel + * handler fires it eagerly: the old turn loop is blocked behind long awaits + * (permission popups, per-event dispatch, tool-result backend calls), so a + * deferred stop would lag by the remaining await window and the old turn + * would visibly keep running. The loop's `stopSent` guard skips a second + * send. See `cancel()` for the idempotency rationale. + * + * We then wait on pendingTurns deletion (the old turn's prompt() finally + * block) — that only runs after runEventTurn returns, which only happens once + * the backend emits turn.completed/turn.failed. With stop already sent, the + * backend aborts in milliseconds, so this wait is short. * * Best-effort: never throws. On timeout, continues anyway. */ @@ -790,7 +820,13 @@ async function preemptInFlightTurn( for (const [reqId, turn] of server.pendingTurns) { if (turn.zcodeSid === zcodeSid && reqId !== selfRequestId) { oldRequestId = reqId; - turn.cancelled = true; // signal the old turn loop to fire stop + wait + turn.cancelled = true; // signal the old turn loop to silent-drain + if (!turn.stopSent) { + stopBackendTurn(server, zcodeSid); + turn.stopSent = true; + } + // Record cancel time (same recovery-window rationale as cancel()). + server.lastCancelledAt.set(zcodeSid, Date.now()); break; } } @@ -798,9 +834,10 @@ async function preemptInFlightTurn( log(` [preempt] in-flight turn ${oldRequestId} found, cancelling`); - // Wait for the old turn to fully exit. The turn loop's cancel handling fires - // stop and keeps looping until the backend emits turn.completed/turn.failed, - // so pendingTurns deletion only happens once the backend is truly done. + // Wait for the old turn to fully exit. With stop already fired above, the + // backend aborts quickly and emits turn.completed; the old turn loop sees + // translator.turnDone and returns, then prompt()'s finally deletes the + // pendingTurns entry — which is what we are waiting on here. const PREEMPT_TIMEOUT_MS = 120_000; const t0 = Date.now(); while (server.pendingTurns.has(oldRequestId)) { @@ -829,7 +866,7 @@ export function extractPromptText(blocks: acp.ContentBlock[] | undefined): strin text?: string; name?: string; uri?: string; - resource?: { text?: string; uri?: string }; + resource?: { text?: string; blob?: string; uri?: string }; }; if (b.type === "text" && b.text) { parts.push(b.text); @@ -843,11 +880,20 @@ export function extractPromptText(blocks: acp.ContentBlock[] | undefined): strin const label = b.name || path; parts.push(`[related resource: ${label}](${path})`); } else if (b.type === "resource" && b.resource) { - // Embedded resource (TextResourceContents). We don't advertise - // embeddedContext, but accept text payloads defensively in case a client - // sends them anyway. - const text = b.resource.text; - if (text) parts.push(text); + // Embedded resource. We don't advertise embeddedContext, but accept text + // payloads defensively in case a client sends them anyway. Binary + // payloads (BlobResourceContents) are never decoded — the base64 blob is + // useless to the model — so rewrite the resource uri into a readable + // filesystem location (same treatment as resource_link). Dropping it + // entirely left the prompt empty, which errored on a binary-only drag. + const r = b.resource; + if (r.text) { + parts.push(r.text); + } else if (r.blob && r.uri) { + const path = r.uri.startsWith("file://") ? fileUriToPath(r.uri) : r.uri; + const label = basename(path) || path; + parts.push(`[related resource: ${label}](${path})`); + } } } return parts.join("\n").trim(); @@ -1030,10 +1076,24 @@ async function runEventTurn( const translator = new EventTranslator(); differ.resetTurn(); const NO_PROGRESS_MS = 120_000; + // Backend's GLM API connection cleanup window after a mid-stream abort. + // Measured: a prompt sent <18s after cancel stalls 80-120s; ≥20s recovers + // to normal. 25s covers the tail of the recovery distribution. + const CANCEL_RECOVERY_WINDOW_MS = 25_000; let lastProgress = Date.now(); let lastStallCheck = Date.now(); let emittedText = false; let emittedOutput = false; + // Thinking-phase feedback: GLM models spend seconds in CoT before emitting + // any model.streaming event, during which the backend is silent and the + // editor shows nothing — users perceive this as "frozen". To bridge that + // gap we emit ONE agent_thought_chunk hint shortly after the turn starts, + // but only if no real output (text / reasoning / tool) has arrived yet. + // It uses a dedicated messageId so it never collides with the real reasoning + // stream (thought_) and is naturally superseded once content flows. + let turnStartedAt: number | null = null; + let thinkingHintSent = false; + const THINKING_HINT_DELAY_MS = 1200; while (Date.now() - lastProgress < NO_PROGRESS_MS) { // Drain + handle server→client requests (interaction/*). Refreshes the @@ -1069,6 +1129,26 @@ async function runEventTurn( const ev = await listener.pollEvent(500); if (ev === null) { + // Thinking-phase hint: if the turn has started but produced no output + // yet (no text/reasoning/tool streamed), and we've been silent longer + // than the threshold, emit a single "thinking" thought chunk so the + // editor shows activity instead of a frozen screen. Skipped once any + // real output has been dispatched, and never sent after cancellation. + if ( + !turn.cancelled && + !thinkingHintSent && + turnStartedAt !== null && + !emittedText && + !emittedOutput && + Date.now() - turnStartedAt > THINKING_HINT_DELAY_MS + ) { + thinkingHintSent = true; + await sendSessionUpdate(cx, acpSid, { + sessionUpdate: "agent_thought_chunk", + content: { type: "text", text: "正在思考…" }, + messageId: `thinking_${chunkMsgId}`, + }); + } // Stall reconciliation: probe authoritative status after 15s of silence. // Skipped while cancelled: we've already fired stop, so the backend will // emit its own completion event, and the reconciliation branch's @@ -1082,20 +1162,66 @@ async function runEventTurn( lastStallCheck = Date.now(); const proj = await monitor.pollOnce(); if (proj?.status === "idle") { - // Turn completed but the event was lost. - if (!emittedText) { - const reply = await fetchLastReply(server, turn.zcodeSid, differ); - if (reply) { - await sendTextChunk(cx, acpSid, reply, chunkMsgId); - } else if (!emittedOutput) { - // No text and no output → suspected failure. - stopBackendTurn(server, turn.zcodeSid); - throw new RequestError(-32603, "turn produced no output"); + // A single idle probe can also fire mid-work: the backend is silent + // during the model's thinking/connection phase and may report idle + // while the turn is still alive. Confirm before trusting it — wait + // briefly, then probe once more. Only a second idle WITH no queued + // events ends the turn: an event arriving in the window proves the + // turn is alive (it stays queued for the next poll). + await sleep(1500); + if (listener.hasQueuedEvents()) { + lastProgress = Date.now(); + continue; // alive — events will be consumed by the next poll + } + const proj2 = await monitor.pollOnce(); + if (proj2?.status === "idle" && !listener.hasQueuedEvents()) { + // Turn completed but the event was lost (double-confirmed). + if (!emittedText) { + const reply = await fetchLastReply(server, turn.zcodeSid, differ); + if (reply) { + await sendTextChunk(cx, acpSid, reply, chunkMsgId); + } else if (!emittedOutput) { + // No text and no output → suspected failure. + stopBackendTurn(server, turn.zcodeSid); + throw new RequestError(-32603, "turn produced no output"); + } } + // Heuristic ending: prompt() must skip auto-compact for this + // turn — the completion was inferred, and compressing an + // in-flight task's context would destroy the work. + turn.stallRecovered = true; + return { stopReason: "end_turn" }; } - return { stopReason: "end_turn" }; + // Second probe says the backend is still working (or events arrived + // mid-probe) — keep waiting; queued events are consumed by the next + // poll iteration. + lastProgress = Date.now(); + if (proj2?.status === "running") { + await listener.resubscribe(() => server.nextId()); + } + continue; } if (proj?.status === "running") { + // Cancel-recovery fast-fail: if this session was cancelled recently + // and the new turn has stalled (turn.started emitted, then silence), + // the backend is in its model-connection recovery window — the model + // request is queued but won't produce output for tens of seconds. + // Rather than hanging 80-120s, surface a recovery hint, stop the + // stalled turn, then switch to silent drain (keep looping until the + // backend emits turn.completed) so pendingTurns isn't cleaned up + // while the backend is still finalizing — preserving the invariant + // that preemptInFlightTurn relies on. + const lastCancel = server.lastCancelledAt.get(turn.zcodeSid); + if (lastCancel && Date.now() - lastCancel < CANCEL_RECOVERY_WINDOW_MS) { + await sendTextChunk(cx, acpSid, "[后端正在从停止中恢复,请稍后重试。]", randomUUID()); + stopBackendTurn(server, turn.zcodeSid); + turn.cancelled = true; + turn.stopSent = true; + // Fall through: the cancelled branch at the top of the next + // iteration + silent drain below will wait for the backend's + // completion event before returning. + continue; + } lastProgress = Date.now(); await listener.resubscribe(() => server.nextId()); } @@ -1105,6 +1231,12 @@ async function runEventTurn( lastProgress = Date.now(); const internalEvents = translator.translate(ev); + // Capture the turn-start timestamp for the thinking-phase hint above. + // Done after translate so the flag flip on the turn.started event is + // observed on the same iteration that processes it. + if (turnStartedAt === null && translator.turnStarted) { + turnStartedAt = Date.now(); + } if (turn.cancelled) { // Silent drain: translate advances the state machine (needed to detect // turnDone below) but we discard every internal event. No text, reasoning, @@ -1115,7 +1247,7 @@ async function runEventTurn( continue; } for (const iev of internalEvents) { - if (iev.kind === "TextDelta") emittedText = true; + if (iev.kind === "TextDelta" || iev.kind === "ReasoningDelta") emittedText = true; if (iev.kind === "ToolCallNew" || iev.kind === "ToolCallUpdate") emittedOutput = true; // Sync usage to the differ so the turn-completion diff doesn't re-emit a // UsageDelta for the same value (the differ's lastUsage baseline is diff --git a/src/server.ts b/src/server.ts index 2c57cc4..5d499f4 100644 --- a/src/server.ts +++ b/src/server.ts @@ -33,6 +33,13 @@ export interface PendingTurn { cancelled: boolean; /** Set once session/stop has been fired for this turn, to avoid re-sending. */ stopSent?: boolean; + /** + * Set when the turn was ended by the stall-recovery heuristic (backend + * reported idle after a silence) rather than a real turn.completed event. + * prompt() skips auto-compact for such turns — the completion was inferred, + * and compressing an in-flight task's context would destroy the work. + */ + stallRecovered?: boolean; } export class ZcodeAcpServer { @@ -90,6 +97,13 @@ export class ZcodeAcpServer { readonly titleEligibleSessions = new Set(); /** Last mode id advertised to the client (acp_sid → modeId), for change detection. */ readonly lastMode = new Map(); + /** + * Timestamp of the last cancel (user stop or preempt), keyed by zcodeSid. + * Set in cancel() and preemptInFlightTurn(); read in runEventTurn's stall + * reconciliation to fast-fail turns that collide with the backend's + * ~20s model-connection recovery window after a mid-stream abort. + */ + readonly lastCancelledAt = new Map(); /** Per-session ProjectionDiffers (persists across turns). */ readonly differs = new Map< string, diff --git a/tests/extract-prompt.test.ts b/tests/extract-prompt.test.ts index f858954..cff23f9 100644 --- a/tests/extract-prompt.test.ts +++ b/tests/extract-prompt.test.ts @@ -116,11 +116,46 @@ describe("extractPromptText", () => { expect(out).toBe("embedded body"); }); - it("skips embedded resources without a text payload", () => { + it("rewrites a binary blob resource to a local file link", () => { + // Dragging a binary file (PDF/zip/…) arrives as BlobResourceContents. + // The base64 blob is never inlined — the uri becomes a readable link so + // a binary-only drop doesn't produce an empty prompt (which errored). const out = extractPromptText([ { type: "resource", - resource: { uri: "file:///x", blob: "aGVsbG8=" }, + resource: { uri: "file:///Users/william/report.pdf", blob: "aGVsbG8=" }, + }, + ] as never); + expect(out).toBe("[related resource: report.pdf](/Users/william/report.pdf)"); + }); + + it("decodes percent-encoded binary resource uris", () => { + const out = extractPromptText([ + { + type: "resource", + resource: { uri: "file:///tmp/my%20doc.pdf", blob: "AAAA" }, + }, + ] as never); + expect(out).toBe("[related resource: my doc.pdf](/tmp/my doc.pdf)"); + }); + + it("keeps non-file:// binary resource uris as-is", () => { + const out = extractPromptText([ + { + type: "resource", + resource: { uri: "https://example.com/file.zip", blob: "AAAA" }, + }, + ] as never); + expect(out).toBe("[related resource: file.zip](https://example.com/file.zip)"); + }); + + it("still skips a blob resource with no uri", () => { + // Defensive: the ACP schema requires uri, but a non-compliant client + // must not crash the prompt. + const out = extractPromptText([ + { + type: "resource", + resource: { blob: "AAAA" }, }, ] as never); expect(out).toBe("");