diff --git a/packages/paperclip-runner/src/drivers/opencode/empty-response.test.ts b/packages/paperclip-runner/src/drivers/opencode/empty-response.test.ts index cf4c0f9337b..610638b77d5 100644 --- a/packages/paperclip-runner/src/drivers/opencode/empty-response.test.ts +++ b/packages/paperclip-runner/src/drivers/opencode/empty-response.test.ts @@ -5,12 +5,13 @@ import { expect, it } from "vitest"; import { OpenCodeServerDriver } from "./opencode-server-driver.js"; import type { PrpEvent } from "../../protocol/replay-contract.js"; -it.each(["reply", "empty-again", "request-fails", "normal", "foreign-idle"] as const)("handles an empty OpenCode response: %s", async mode => { +it.each(["reply", "reply-no-finish", "reply-tool-finish", "slow-native-tool", "idle-stall", "tool-idle-stall", "empty-again", "request-fails", "normal", "foreign-idle", "queued-tool"] as const)("handles an empty OpenCode response: %s", async mode => { const root = await mkdtemp(join(tmpdir(), "opencode-empty-response-")); const command = join(root, "fake-opencode.mjs"); await copyFile(resolve("test/fixtures/fake-opencode-server.mjs"), command); await chmod(command, 0o755); const prompts: Record[] = []; + let toolTimer: ReturnType | undefined; let stream: ReadableStreamDefaultController | undefined; const queued: Uint8Array[] = []; const emit = (value: unknown) => { const frame = new TextEncoder().encode(`data: ${JSON.stringify(value)}\n\n`); if (stream) stream.enqueue(frame); else queued.push(frame); }; @@ -27,8 +28,24 @@ it.each(["reply", "empty-again", "request-fails", "normal", "foreign-idle"] as c const number = prompts.length, messageID = `assistant-${number}`; queueMicrotask(() => { if (mode === "foreign-idle") emit({ type: "session.idle", properties: { sessionID: "foreign-session" } }); - emit({ type: "message.updated", properties: { info: { id: messageID, sessionID, role: "assistant", finish: "stop", time: { completed: Date.now() } } } }); - const answer = mode === "normal" || mode === "foreign-idle" || number === 2 && mode === "reply"; + const incompleteHeader = number === 2 && ["reply-no-finish", "reply-tool-finish", "idle-stall", "tool-idle-stall"].includes(mode); + emit({ type: "message.updated", properties: { info: { id: messageID, sessionID, role: "assistant", + ...(incompleteHeader ? ["reply-tool-finish", "tool-idle-stall"].includes(mode) ? { finish: "tool-calls" } : {} : { finish: "stop", time: { completed: Date.now() } }) } } }); + if (mode === "slow-native-tool" && number === 2 || mode === "queued-tool") { + const toolPart = { id: `native-${number}`, messageID, sessionID, type: "tool", tool: "bash", callID: `call-${number}`, + state: { status: mode === "queued-tool" ? "pending" : "running", input: { command: "owned-controlled-command" } } }; + emit({ type: "message.part.updated", properties: { part: toolPart } }); + if (mode === "slow-native-tool") { + emit({ type: "session.idle", properties: { sessionID } }); + toolTimer = setTimeout(() => { + emit({ type: "message.part.updated", properties: { part: { ...toolPart, state: { ...toolPart.state, status: "completed", output: "Owned tool completed.", time: { start: 1, end: 2 } } } } }); + emit({ type: "message.part.updated", properties: { part: { id: `part-${number}`, messageID, sessionID, type: "text", text: "Here is the actual final answer.", time: { start: 3, end: 4 } } } }); + emit({ type: "session.idle", properties: { sessionID } }); + }, 22_000); + return; + } + } + const answer = mode === "normal" || mode === "foreign-idle" || mode === "queued-tool" || number === 2 && ["reply", "reply-no-finish", "reply-tool-finish"].includes(mode); emit({ type: "message.part.updated", properties: { sessionID, part: { id: `part-${number}`, messageID, type: answer ? "text" : "reasoning", text: answer ? "Here is the actual final answer." : "Synthetic reasoning must not become the answer.", time: { start: 1, end: 2 } } } }); emit({ type: "session.idle", properties: { sessionID } }); @@ -40,24 +57,29 @@ it.each(["reply", "empty-again", "request-fails", "normal", "foreign-idle"] as c }, }); const session = await driver.openSession({ runId: "owned-run", normalizedSessionId: "owned-session", workingDirectory: root }); + let deadline: ReturnType | undefined; try { const collected = (async () => { const rows: PrpEvent[] = []; for await (const event of session.events()) { rows.push(event); if (["turn.completed", "turn.failed"].includes(event.eventType)) break; } return rows; })(); const { turnId } = await session.startTurn({ message: { role: "user", text: "Answer the current request." }, reasoningMode: "disabled" }); - const events = await collected; - const succeeds = ["reply", "normal", "foreign-idle"].includes(mode); + const events = await Promise.race([collected, new Promise((_, reject) => { + deadline = setTimeout(() => reject(new Error("Controlled provider produced no terminal event")), mode.endsWith("idle-stall") || mode === "slow-native-tool" ? 26_000 : 5_000); + })]); + const succeeds = ["reply", "reply-no-finish", "reply-tool-finish", "slow-native-tool", "normal", "foreign-idle", "queued-tool"].includes(mode); expect(events.at(-1)?.eventType).toBe(succeeds ? "turn.completed" : "turn.failed"); expect(events.filter(event => event.eventType === "turn.started")).toHaveLength(1); expect(events.every(event => !event.turnId || event.turnId === turnId)).toBe(true); const final = events.filter(event => event.eventType === "item.completed" && event.payload.kind === "agentMessage" && event.payload.channel === "final"); expect(final.map(event => event.payload.text)).toEqual(succeeds ? ["Here is the actual final answer."] : []); - expect(prompts).toHaveLength(["normal", "foreign-idle"].includes(mode) ? 1 : 2); + expect(prompts).toHaveLength(["normal", "foreign-idle", "queued-tool"].includes(mode) ? 1 : 2); if (prompts.length === 2) { expect(prompts[1]).toMatchObject({ providerID: prompts[0]!.providerID, modelID: prompts[0]!.modelID, system: prompts[0]!.system, variant: "paperclip-no-reasoning" }); expect(JSON.stringify(prompts[1]!.parts)).toContain("Do not repeat completed actions"); } } finally { + clearTimeout(deadline); + clearTimeout(toolTimer); await session.close({ reason: "controlled test complete" }); await rm(root, { recursive: true, force: true }); } diff --git a/packages/paperclip-runner/src/drivers/opencode/opencode-server-driver.ts b/packages/paperclip-runner/src/drivers/opencode/opencode-server-driver.ts index e7e83d43758..e21e3af9ff9 100644 --- a/packages/paperclip-runner/src/drivers/opencode/opencode-server-driver.ts +++ b/packages/paperclip-runner/src/drivers/opencode/opencode-server-driver.ts @@ -542,8 +542,10 @@ class OpenCodeHarnessSession implements HarnessSession { #completionSettlement: Promise | null = null; #turnStartSourceSeq = 0; #turnReasoningMode: OpenCodeReasoningMode = "default"; - #emptyResponseRecovery: { turnId: string; priorMessages: Set; responseFinished: boolean } | null = null; + #emptyResponseRecovery: { turnId: string; priorMessages: Set; responseStarted: boolean; responseFinished: boolean } | null = null; #emptyResponseAckTimer: ReturnType | undefined; + #pendingToolCalls = 0; + readonly #runningNativeToolParts = new Set(); #abort = new AbortController(); constructor(input: { @@ -693,6 +695,7 @@ class OpenCodeHarnessSession implements HarnessSession { this.#turnStartSourceSeq = this.#sourceSequence; this.#turnReasoningMode = reasoningMode; this.#emptyResponseRecovery = null; + this.#runningNativeToolParts.clear(); this.#emit("turn.submitted", { envelopeSchema: this.#taskEnvelope.schema, text: input.message.text, @@ -752,8 +755,17 @@ class OpenCodeHarnessSession implements HarnessSession { this.#emptyResponseAckTimer = undefined; } + #armEmptyResponseAckTimer(turnId: string, message: string): void { + if (this.#emptyResponseAckTimer) return; + this.#emptyResponseAckTimer = setTimeout(() => { + this.#emptyResponseAckTimer = undefined; + this.#failEmptyResponse(turnId, message); + }, 20_000); + this.#emptyResponseAckTimer.unref(); + } + #failEmptyResponse(turnId: string, message: string): void { - if (this.#closed || this.#activeTurnId !== turnId || this.#result !== null) return; + if (this.#closed || this.#activeTurnId !== turnId || this.#result !== null || this.#pendingToolCalls > 0 || this.#runningNativeToolParts.size > 0) return; this.#emit("turn.failed", { status: "failed", error: { code: "opencode_empty_response", message, retryable: false } }, { turnId }); this.#terminalTurns.set(turnId, canonicalJson({ status: "failed" })); this.#activeTurnId = null; @@ -761,20 +773,27 @@ class OpenCodeHarnessSession implements HarnessSession { #recoverEmptyResponse(turnId: string): boolean { if (this.#result !== null || this.#pendingRuntimeRequests.size > 0) return false; + if (this.#pendingToolCalls > 0 || this.#runningNativeToolParts.size > 0) return true; const recovery = this.#emptyResponseRecovery; - // Both idle event forms can remain queued from the empty response. Wait - // for the correction's own completed assistant message before settling. - if (recovery && !recovery.responseFinished) return true; const boundary = Math.max(this.#turnStartSourceSeq, this.#lastNonTerminalToolSourceSeq); if (this.#completedTextParts.some(part => part.observedSourceSeq > boundary)) return false; + // Both idle event forms can remain queued from the empty response. Wait + // for correction evidence. A completed answer part is sufficient even + // when its message header omits completion metadata. An idle response + // with neither answer nor finish evidence gets a bounded grace period; + // active provider/tool work still follows the original outer deadline. + if (recovery && !recovery.responseFinished) { + if (recovery.responseStarted) + this.#armEmptyResponseAckTimer(turnId, "OpenCode became idle without completing its requested final response."); + return true; + } if (recovery) { this.#failEmptyResponse(turnId, "OpenCode ended without a final answer or accepted completion report after one correction."); return true; } - this.#emptyResponseRecovery = { turnId, priorMessages: new Set(this.#messageRoles.keys()), responseFinished: false }; + this.#emptyResponseRecovery = { turnId, priorMessages: new Set(this.#messageRoles.keys()), responseStarted: false, responseFinished: false }; this.#emit("harness.diagnostic", { code: "opencode_empty_response_correction", message: "Requesting one final response after an empty OpenCode completion." }, { turnId }); - this.#emptyResponseAckTimer = setTimeout(() => this.#failEmptyResponse(turnId, "OpenCode did not start its requested final response."), 20_000); - this.#emptyResponseAckTimer.unref(); + this.#armEmptyResponseAckTimer(turnId, "OpenCode did not start its requested final response."); void this.#submitPrompt("Your response ended without a user-visible final answer or an accepted completion report. Continue this same request from the work already done. Give the user a concise final answer and submit paperclip_finish (or paperclip_block when blocked) with the current completion contract. Do not repeat completed actions.") .catch(() => this.#failEmptyResponse(turnId, "OpenCode could not request a final response after an empty completion.")); return true; @@ -1086,6 +1105,13 @@ class OpenCodeHarnessSession implements HarnessSession { callId: string; arguments: unknown; }): Promise { + this.#pendingToolCalls += 1; + this.#clearEmptyResponseAckTimer(); + try { return await this.#dispatchToolCall(call); } + finally { this.#pendingToolCalls -= 1; } + } + + async #dispatchToolCall(call: { tool: string; callId: string; arguments: unknown }): Promise { // The authenticated MCP bridge has resolved this against its closed // declared catalog. A second prefix strip changes legitimate operation IDs. const tool = call.tool; @@ -1645,6 +1671,8 @@ class OpenCodeHarnessSession implements HarnessSession { ); if (sessionId && sessionId !== this.#providerSessionId) return; const turnId = this.#activeTurnId; + if (this.#emptyResponseRecovery?.responseStarted && type === "session.status" && text(record(properties.status).type) === "busy") + this.#clearEmptyResponseAckTimer(); if (type === "question.asked" && turnId) { this.#acceptQuestion(properties); return; @@ -1748,6 +1776,11 @@ class OpenCodeHarnessSession implements HarnessSession { this.#streamingParts.set(text(part.id), part); } const role = this.#messageRoles.get(messageId); + const recovery = this.#emptyResponseRecovery; + if (role === "assistant" && recovery?.responseStarted && !recovery.priorMessages.has(messageId) && this.#emptyResponseAckTimer) { + this.#clearEmptyResponseAckTimer(); + this.#armEmptyResponseAckTimer(owningTurnId, "OpenCode became idle without completing its requested final response."); + } if (role === "assistant") this.#emitAssistantPart(part, owningTurnId); else if (role === undefined) { const pending = this.#pendingMessageParts.get(messageId) ?? []; @@ -1771,9 +1804,11 @@ class OpenCodeHarnessSession implements HarnessSession { const role = text(info.role); const recovery = this.#emptyResponseRecovery; if (recovery?.turnId === turnId && role === "assistant" && messageId && !recovery.priorMessages.has(messageId)) { - this.#clearEmptyResponseAckTimer(); - if ((Number.isFinite(record(info.time).completed) || text(info.finish)) && !["tool-calls", "tool_calls"].includes(text(info.finish))) - recovery.responseFinished = true; + const toolCalls = ["tool-calls", "tool_calls"].includes(text(info.finish)); + const finished = !!(Number.isFinite(record(info.time).completed) || text(info.finish)) && !toolCalls; + if (!recovery.responseStarted || finished) this.#clearEmptyResponseAckTimer(); + recovery.responseStarted = true; + if (finished) recovery.responseFinished = true; } // Record the message's owning turn at the moment OpenCode first // reports it. A later turn that reuses the same native message id @@ -1919,6 +1954,12 @@ class OpenCodeHarnessSession implements HarnessSession { const partId = text(part.id, `${turnId}:part`); const partType = text(part.type, "unknown"); const messageId = text(part.messageID, text(part.messageId)) || null; + if (turnId === this.#activeTurnId && ["tool", "tool-call", "tool_call"].includes(partType)) { + if (text(record(part.state).status) === "running") { + this.#runningNativeToolParts.add(partId); + this.#clearEmptyResponseAckTimer(); + } else this.#runningNativeToolParts.delete(partId); + } const canonicalToolName = canonicalOpenCodeMcpToolName( canonicalOpenCodeDisplayToolName( text(part.tool, text(part.name)),