Telemetry: tool-input-delta re-reads the tool part from SQLite on every streamed chunk (75% of all spans)

[jack-champagne]

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
  return

ensureToolCall (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)
  return

This 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.ts is pure upstream — no harmoniqs-authored commit touches it (only 017a5977d, upstream #39317). A fix probably belongs upstream at sst/opencode, with a fork patch as a stopgap.
• handleEvent is Effect.fnUntraced (:278), so the switch itself is untraced; only the named Effect.fn helpers 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.

[jack-champagne]

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).