Repository navigation
Telemetry: tool-input-delta re-reads the tool part from SQLite on every streamed chunk (75% of all spans) #122
Description
Summary
tool-input-delta calls ensureToolCall(value) on every streamed chunk of a tool call's arguments. ensureToolCall unconditionally calls readToolCall, which does a SQLite getPart read — so we pay one SELECT plus three spans per chunk, and the result is discarded.
Measured on a real production run: 75.4% of all spans in the trace are this loop.
Code path (verified at 1.18.12, 50f8eb0)
packages/opencode/src/session/processor.ts:322
case "tool-input-start":
if (ctx.assistantMessage.summary) { throw ... }
yield* ensureToolCall(value) // creates the tool part
return
case "tool-input-delta":
yield* ensureToolCall(value) // <-- result discarded; part already exists
returnensureToolCall (processor.ts:216) begins with:
const existing = yield* readToolCall(input.id)
if (existing) {
if (!input.providerExecuted || existing.part.metadata?.providerExecuted) return existing
...
}and readToolCall (processor.ts:129) goes to the DB even though the call metadata is already in memory:
const call = ctx.toolcalls[toolCallID]
if (!call) return undefined
const part = yield* session.getPart({ partID: call.partID, messageID: call.messageID, sessionID: call.sessionID })tool-input-delta cannot carry providerExecuted. Its schema is { type, id, name, text } — packages/llm/src/schema/events.ts:136-141:
export const ToolInputDelta = Schema.Struct({
type: Schema.tag("tool-input-delta"),
id: ToolCallID,
name: Schema.String,
text: Schema.String,
})So on every delta after the first, line 223 early-returns existing with no write. The entire call is one wasted SELECT and three wasted spans.
Because readToolCall and ensureToolCall are Effect.fn(...)-traced and Session.getPart wraps sql.execute, each delta emits 4 spans: ensureToolCall → readToolCall → getPart → sql.execute.
Measured impact
From one production opencode run (2.15 h, opencode 1.18.10, 4 sessions, 159 tool calls, 112 LLM calls), reassembled from 2,593 raw OTLP objects in the run corpus:
| span | count |
|---|---|
SessionProcessor.ensureToolCall |
24,051 |
SessionProcessor.readToolCall |
24,590 |
Session.getPart |
24,590 |
sql.execute (child of getPart) |
24,590 |
| loop total | 97,980 of 129,881 = 75.4% |
24,051 ensureToolCall / 159 tool calls = 151× per tool call — i.e. the average number of streamed argument chunks.
Parent→child edge counts confirm the chain is exactly as described:
24590 Session.getPart -> sql.execute
24590 SessionProcessor.readToolCall -> Session.getPart
24051 SessionProcessor.ensureToolCall -> SessionProcessor.readToolCall
24051 SessionProcessor.process -> SessionProcessor.ensureToolCall
Latency cost is small — 8.0 s of wall time across all 24,590 getPart calls (~0.33 ms each; it's local SQLite). This is a telemetry-volume problem, not a performance problem. It is the single largest contributor to unusably large traces.
Suggested fix
Guard the delta path on the in-memory map, which is exactly what readToolCall consults first:
case "tool-input-delta":
if (!ctx.toolcalls[value.id]) yield* ensureToolCall(value)
returnThis keeps the idempotent-create behaviour for providers that emit deltas without a preceding tool-input-start, and removes the round-trip when the entry already exists. Expected: 24,051 → ~159 ensureToolCall calls, and the trace drops from 129,839 to ~35,500 spans.
tool-input-end (:327) does the same thing and could take the same guard, though at 159 calls it is not material.
Behavioural nuance a reviewer will ask about
readToolCall self-heals a stale cache entry: if the DB part is missing or not type === "tool" it deletes ctx.toolcalls[id] and returns undefined, causing ensureToolCall to recreate the part. Guarding the delta path skips that self-heal on deltas only. tool-input-end and tool-call (:335) still call ensureToolCall unguarded, so the heal still happens, one step later.
Notes
processor.tsis pure upstream — no harmoniqs-authored commit touches it (only017a5977d, upstream#39317). A fix probably belongs upstream atsst/opencode, with a fork patch as a stopgap.handleEventisEffect.fnUntraced(:278), so the switch itself is untraced; only the namedEffect.fnhelpers emit spans.- Related: the trace-scoping issue filed alongside this one. That one matters more — this reduces volume, that one makes traces usable at all.
Activity
jack-champagne commentedon Aug 5, 2026
Related: #123 (trace scoping — the more consequential of the two). Platform-side gaps found in the same investigation: harmoniqs/aws-infra#235 (ingest does not log source IP), harmoniqs/aws-infra#236 (no alarm on high-volume successful ingest — this bug's output went unnoticed for a week).