diff options
| author | Adam Malczewski <[email protected]> | 2026-06-07 17:07:47 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-07 17:07:47 +0900 |
| commit | 3ecc9778fe278d6665b1e9a918f44c16f6992b87 (patch) | |
| tree | 57e14412d782469d2a744ce9da9eded8bb2a5bd6 /packages/kernel/src/runtime/run-turn.ts | |
| parent | d2ac57045e9884e5f948b95014e853111cd6bc3d (diff) | |
| download | dispatch-3ecc9778fe278d6665b1e9a918f44c16f6992b87.tar.gz dispatch-3ecc9778fe278d6665b1e9a918f44c16f6992b87.zip | |
feat(kernel-runtime): per-step TTFT + decode timing spans (observability)
Split each step's generation into a ttft span (stream start -> first text|reasoning
token) and a decode span (first token -> stream end), children of the step span.
decode = generation total - TTFT; both retrievable from the trace-store. First token
counts reasoning deltas; a step with no content token ends ttft with firstToken:false
(no misleading decode). Span-based (no clock injection), no wire/contract change.
+3 runtime tests. GLOSSARY: TTFT + decode time.
typecheck clean; 512 vitest; biome 0/0.
Diffstat (limited to 'packages/kernel/src/runtime/run-turn.ts')
| -rw-r--r-- | packages/kernel/src/runtime/run-turn.ts | 67 |
1 files changed, 66 insertions, 1 deletions
diff --git a/packages/kernel/src/runtime/run-turn.ts b/packages/kernel/src/runtime/run-turn.ts index b722f3f..a8ee6c9 100644 --- a/packages/kernel/src/runtime/run-turn.ts +++ b/packages/kernel/src/runtime/run-turn.ts @@ -86,6 +86,12 @@ interface StepContext { readonly cwd: string | undefined; } +interface TimingState { + ttftSpan: Span | undefined; + decodeSpan: Span | undefined; + firstTokenSeen: boolean; +} + interface StepResult { readonly assistantMessage: ChatMessage | undefined; readonly toolCalls: ToolCall[]; @@ -101,13 +107,42 @@ function processEvent( dispatcher: StepDispatcher, ctx: StepContext, stepSpan: Span | undefined, + timing: TimingState, ): void { switch (event.type) { case "text-delta": + if (!timing.firstTokenSeen) { + timing.firstTokenSeen = true; + try { + timing.ttftSpan?.end({ attrs: { firstToken: true } }); + } catch { + // Swallow — D7. + } + timing.ttftSpan = undefined; + try { + timing.decodeSpan = stepSpan?.child("decode"); + } catch { + // Swallow — D7. + } + } appendTextDelta(chunks, event.delta); ctx.emit(textDeltaEvent(ctx.conversationId, ctx.turnId, event.delta)); break; case "reasoning-delta": + if (!timing.firstTokenSeen) { + timing.firstTokenSeen = true; + try { + timing.ttftSpan?.end({ attrs: { firstToken: true } }); + } catch { + // Swallow — D7. + } + timing.ttftSpan = undefined; + try { + timing.decodeSpan = stepSpan?.child("decode"); + } catch { + // Swallow — D7. + } + } appendThinkingDelta(chunks, event.delta); ctx.emit(reasoningDeltaEvent(ctx.conversationId, ctx.turnId, event.delta)); break; @@ -211,6 +246,21 @@ async function executeStep(ctx: StepContext): Promise<StepResult> { ctx.cwd, ); + const timing: TimingState = { + ttftSpan: undefined, + decodeSpan: undefined, + firstTokenSeen: false, + }; + + // Open TTFT span when spans are enabled + try { + if (stepSpan !== undefined) { + timing.ttftSpan = stepSpan.child("ttft"); + } + } catch { + // Swallow — D7. + } + try { const opts = { ...(ctx.turnSpan !== undefined && stepSpan !== undefined ? { logger: stepSpan.log } : {}), @@ -218,7 +268,7 @@ async function executeStep(ctx: StepContext): Promise<StepResult> { const stream = ctx.provider.stream(ctx.messages, ctx.tools, opts); for await (const event of stream) { if (ctx.signal.aborted) break; - processEvent(event, chunks, toolCalls, dispatcher, ctx, stepSpan); + processEvent(event, chunks, toolCalls, dispatcher, ctx, stepSpan, timing); if (event.type === "usage") { stepUsage = addUsage(stepUsage, event.usage); } @@ -240,6 +290,21 @@ async function executeStep(ctx: StepContext): Promise<StepResult> { stepSpan = undefined; } + // Close timing spans: if no first token was seen, end ttft with firstToken: false + // If decode span is open, close it + try { + if (timing.ttftSpan !== undefined) { + timing.ttftSpan.end({ attrs: { firstToken: false } }); + timing.ttftSpan = undefined; + } + if (timing.decodeSpan !== undefined) { + timing.decodeSpan.end(); + timing.decodeSpan = undefined; + } + } catch { + // Swallow — D7. + } + if (!ctx.dispatch.eager) { for (const call of toolCalls) { dispatcher.submit(call); |
