mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-10 12:37:55 +01:00
fix(runner): keep discarded OpenCode token deltas from delaying tool calls (#20209)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - Native OpenCode runs use a TypeScript app-server proxy between OpenCode and runnerd > - runnerd reads the proxy's frames in order, only after the controller acknowledges earlier events > - For each frame, runnerd rewrites its whole durable provider state with fsync, including every tool result that the turn retains > - The proxy sent one `item/delta` frame for each reasoning or tool-output token, and runnerd discards `item/delta` > - A Paperclip tool call request therefore waited behind hundreds of discarded frames, and the wait grew with each tool result in the turn > - This pull request stops the proxy from sending the token deltas that runnerd does not consume > - The benefit is that tool calls reach runnerd without that queue, so agent turns finish faster ## Linked Issues or Issue Description **What happened** In the chat eval `plugins.configure-plugin` (runner-opencode, deepseek-v4.1-flash, GitHub Actions run 42574640038), `paperclip_search_api` calls in one turn slowed from about 1.4 s to 9-15 s each. The server handled every call in 50-250 ms (`tool.execution` spans). For one `call_api` call, 6.3 s passed between the server's 403 and the next agent activity. Time to first token was about 4.4 s. The run events show the cause. Events that OpenCode streams reach runnerd in bursts. In one burst, the usage events for three different model requests arrived within 0.5 s, which no model can do. Each burst ends with the next tool call request. 143 of 203 recorded runner-opencode runs that we checked show such bursts, and 108 show a gap of 8 s or more. Many chat eval cases that time out use this runner. The mechanism: 1. OpenCode streams reasoning one token at a time. The proxy forwarded each token as its own `item/delta` frame. 2. runnerd reads proxy frames in order and only after the controller acknowledges earlier events. For each frame it calls `save_state`. That serializes the whole provider state, with the tool results retained in the turn, and fsyncs it. 3. runnerd's Codex facade has no mapping for `item/delta`, so it discards the frame after the save. 4. A tool call request is one more frame in the same ordered stream. It waits until runnerd works through every earlier delta frame. The wait is about (reasoning tokens) x (save cost), and the save cost grows with each retained tool result. **Expected behavior** A Paperclip tool call reaches runnerd soon after OpenCode makes it. Its delay does not grow with the reasoning length or with the number of earlier tool calls in the turn. **Steps to reproduce** 1. Run a native OpenCode chat turn with a reasoning model that makes many sequential Paperclip tool calls, for example `search_api`. 2. Compare each tool's `item.completed` tool_result time with the `tool.execution.completed` time and with the next `item.started` tool_use time in the run events. 3. See that the gap grows during the turn, and that events for several model requests arrive within less than one second. 4. For a local model of the mechanism: run the pinned OpenCode binary with a controlled OpenAI-compatible provider that streams 300 reasoning tokens before each tool call. Pass the driver events through the proxy's mapping and batching into a reader that consumes one frame at a time with a save cost that grows by 4 ms per completed tool result. Before this change, 8 sequential calls waited 1.7, 3.1, 4.2, 5.4, 6.7, 7.9, 9.2 and 10.5 s behind 142-261 queued frames. After this change, they waited 64-93 ms behind 0 frames. ## What Changed - `shouldForwardOpenCodeProxyItem` now takes the event type and payload. For `item.delta`, it forwards only assistant text (`agentMessage` or `text`), which runnerd maps to `item/agentMessage/delta`. - The proxy keeps reasoning and tool-output token deltas. Completed reasoning and tool items still go to runnerd as `item/completed`. Tool progress still goes as `item/updated`. - New regression test: a step with 1,000 streamed reasoning and tool-output tokens puts the same number of frames before the tool call request as a step with 1 token, and no `item/delta` frame is written. - New test: assistant text deltas are still forwarded. Completed reasoning items are still forwarded. ## Verification - `pnpm exec vitest run src/cli/opencode-proxy-events.test.ts src/cli/opencode-proxy-output.test.ts` in `packages/paperclip-runner`: 15 passed. - Red/green: with the predicate change reverted, the two new tests fail. With the change, they pass. - `tsc --noEmit -p tsconfig.test.json` in `packages/paperclip-runner` has no errors in the changed files. Local errors exist only in `src/eval/workflow-harness.ts`, which needs a built `@paperclipai/paperclip-eval-kernel`. - Local before/after measurement with the real pinned OpenCode binary (`opencode-ai@1.18.34`), described in Steps to reproduce, step 4. - Not run locally: the suites that need the `paperclip-runnerd` debug binary or the bundled provider entrypoints (`runnerd-opencode-streaming-tools`, `runnerd-codex-transport`, `opencode-proxy-thread-read`). They fail the same way on the unchanged base in this worktree because those build outputs are missing. CI covers them. ## Risks - Low risk. The changed frames were discarded by runnerd. No persisted state shape changes, so no previous-release story is needed. - If runnerd later maps a reasoning delta method, the proxy must forward it with batching, as it does for assistant text. The test names this boundary. - This change does not change the per-frame durable save in runnerd. Mapped frames (assistant text, tool items) still pay it. A runnerd change that skips the save when a notification changes no state would protect other proxies too. That is a separate change. > For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and discuss it in `#dev` before opening the PR. Feature PRs that overlap with planned core work may need to be redirected — check the roadmap first. See `CONTRIBUTING.md`. ## Model Used - Anthropic Claude Opus 5.5 (`claude-opus-5-5`), used through Claude Code with tool use (shell, file edits, local benchmarks). ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [ ] All Paperclip CI gates are green - [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
1 parent
09e24dd12c
commit
9c18cf61da
3 files changed
+52
-7
No files matched your search
@@ -220,8 +220,9 @@ async function pumpEvents(opened: HarnessSession): Promise<void> {
|
||||
// correctly trip the facade's strict turn-binding validator.
|
||||
if (
|
||||
!shouldForwardOpenCodeProxyItem({
|
||||
eventType: event.eventType,
|
||||
turnId: event.turnId,
|
||||
kind: payload.kind,
|
||||
payload,
|
||||
})
|
||||
)
|
||||
continue;
|
||||
|
||||
@@ -1,4 +1,4 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { describe, expect, it, vi } from "vitest";
|
||||
|
||||
import {
|
||||
boundedOpenCodeTerminalError,
|
||||
@@ -8,17 +8,59 @@ import {
|
||||
shouldAnnounceOpenCodeProxyTurn,
|
||||
shouldForwardOpenCodeProxyItem,
|
||||
} from "./opencode-proxy-events.js";
|
||||
import { createOpenCodeProxyOutput } from "./opencode-proxy-output.js";
|
||||
|
||||
describe("OpenCode runnerd proxy event boundary", () => {
|
||||
it("drops only the duplicate session-scoped model item", () => {
|
||||
expect(shouldForwardOpenCodeProxyItem({ kind: "model" })).toBe(false);
|
||||
expect(shouldForwardOpenCodeProxyItem({ payload: { kind: "model" } })).toBe(false);
|
||||
expect(
|
||||
shouldForwardOpenCodeProxyItem({
|
||||
turnId: "turn-1",
|
||||
kind: "model",
|
||||
payload: { kind: "model" },
|
||||
}),
|
||||
).toBe(true);
|
||||
expect(shouldForwardOpenCodeProxyItem({ kind: "agentMessage" })).toBe(true);
|
||||
expect(shouldForwardOpenCodeProxyItem({ payload: { kind: "agentMessage" } })).toBe(true);
|
||||
});
|
||||
|
||||
it("keeps per-token deltas runnerd discards from queueing ahead of a tool call", () => {
|
||||
const framesBeforeToolCall = (tokens: number) => {
|
||||
vi.useFakeTimers();
|
||||
try {
|
||||
const written: Array<{ method?: string }> = [];
|
||||
const output = createOpenCodeProxyOutput(frame => written.push(frame as { method?: string }));
|
||||
const forward = (eventType: "item.started" | "item.delta" | "item.completed", itemId: string, payload: Record<string, unknown>) => {
|
||||
if (shouldForwardOpenCodeProxyItem({ eventType, turnId: "turn-1", payload }))
|
||||
output.send(openCodeProxyItemNotification({ eventType, threadId: "thread-1", turnId: "turn-1", itemId, payload }));
|
||||
};
|
||||
for (let index = 0; index < tokens; index += 1) {
|
||||
forward("item.delta", "reasoning-1", { kind: "reasoning", channel: "detail", providerPhase: "reasoning", text: `token ${index} `,
|
||||
item: { id: "reasoning-1", type: "reasoning", text: `token ${index} ` } });
|
||||
forward("item.delta", "tool-1", { kind: "tool", text: `line ${index}\n`, item: { id: "tool-1", type: "tool", state: { status: "running" } } });
|
||||
}
|
||||
forward("item.completed", "reasoning-1", { kind: "reasoning", text: "Reasoning summary.",
|
||||
item: { id: "reasoning-1", type: "reasoning", text: "Reasoning summary." } });
|
||||
output.send({ id: "opencode-1", method: "item/tool/call", params: { tool: "search_api" } });
|
||||
const position = written.findIndex(frame => frame.method === "item/tool/call");
|
||||
expect(position).toBeGreaterThanOrEqual(0);
|
||||
expect(written.some(frame => frame.method === "item/delta")).toBe(false);
|
||||
expect(written.at(position - 1)).toMatchObject({ method: "item/completed", params: { kind: "reasoning" } });
|
||||
return position;
|
||||
} finally {
|
||||
vi.useRealTimers();
|
||||
}
|
||||
};
|
||||
expect(framesBeforeToolCall(1_000)).toBe(framesBeforeToolCall(1));
|
||||
});
|
||||
|
||||
it("still forwards streamed assistant text for runnerd's live reply", () => {
|
||||
const payload = { kind: "agentMessage", channel: "progress", text: "Checking the plugin.", item: { type: "agentMessage" } };
|
||||
expect(shouldForwardOpenCodeProxyItem({ eventType: "item.delta", turnId: "turn-1", payload })).toBe(true);
|
||||
expect(shouldForwardOpenCodeProxyItem({ eventType: "item.delta", turnId: "turn-1",
|
||||
payload: { kind: "text", text: "Legacy text part." } })).toBe(true);
|
||||
expect(shouldForwardOpenCodeProxyItem({ eventType: "item.delta", turnId: "turn-1",
|
||||
payload: { kind: "reasoning", text: "Private reasoning" } })).toBe(false);
|
||||
expect(shouldForwardOpenCodeProxyItem({ eventType: "item.completed", turnId: "turn-1",
|
||||
payload: { kind: "reasoning", text: "Private reasoning" } })).toBe(true);
|
||||
});
|
||||
|
||||
it("announces one outer turn when SSE wins the response race", () => {
|
||||
|
||||
@@ -20,10 +20,12 @@ export function openCodeProxyToolNotification(input: {
|
||||
}
|
||||
|
||||
export function shouldForwardOpenCodeProxyItem(input: {
|
||||
eventType?: string;
|
||||
turnId?: string;
|
||||
kind?: unknown;
|
||||
payload: Record<string, unknown>;
|
||||
}): boolean {
|
||||
return !(input.turnId === undefined && input.kind === "model");
|
||||
if (input.eventType === "item.delta") return openCodeProxyAssistantText(input.payload) !== null;
|
||||
return !(input.turnId === undefined && input.payload.kind === "model");
|
||||
}
|
||||
|
||||
export function openCodeProxyAssistantText(
|
||||
|
||||
Reference in new issue
Block a user