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.

3 files changed, 213 insertions, 1 deletions

diff --git a/GLOSSARY.md b/GLOSSARY.md
index 0ec7ea2..65aa6f2 100644
--- a/GLOSSARY.md
+++ b/GLOSSARY.md
@@ -18,6 +18,8 @@
 | **turn** | One user message → assistant response cycle (may span multiple steps). | — |
 | **step** | One LLM round-trip within a turn (may emit multiple tool calls). | iteration |
 | **stepId** | The identifier of a step, stamped on each `tool-call`/`tool-result` event and tool chunk it produces, so a client groups a parallel/batched tool-call set by equality. Branded `StepId`; the runtime derives it deterministically as `<turnId>#<stepIndex>` (0-based). Generation provenance carried ON the tool chunk (unlike `seq`, which is a store-assigned sync cursor on the `StoredChunk` envelope). Treat as opaque. | batchId, step index (as the wire key) |
+| **TTFT** (time to first token) | Per-step latency from the generation stream starting to the first content token (text **or** reasoning) arriving. Inherently per LLM round-trip — each step re-prefills, so a turn has one TTFT per step; step 0's is the turn's user-visible first-token latency, and the sum across steps is the total prefill overhead. Captured as observability span timing only (not on the wire). | time-to-first-byte (when meaning tokens) |
+| **decode time** | The generation time of a step *after* the first token — first token → stream end, i.e. the step's generation total minus its TTFT. The model's token-production time with first-token latency removed. Observability span timing. | — |
 | **tool call** | A model's request to run a tool within a step. | function call (when meaning a tool call) |
 | **chunk** | One ordered piece of a message (text, thinking, tool-call/result, etc.), append-only in the log. | block, segment |
 | **seq** | The monotonic, gap-free, per-conversation sequence number stamped on each chunk as it is appended to the log. The sync cursor: a client requests `?sinceSeq=N` to fetch only newer chunks. Storage/sync metadata, never message content. | cursor (when meaning the number), offset, index |
diff --git a/packages/kernel/src/runtime/run-turn.test.ts b/packages/kernel/src/runtime/run-turn.test.ts
index 42a846b..089f65b 100644
--- a/packages/kernel/src/runtime/run-turn.test.ts
+++ b/packages/kernel/src/runtime/run-turn.test.ts
@@ -1161,6 +1161,151 @@ describe("runTurn", () => {
 			);
 			expect(logRecords).toHaveLength(0);
 		});
+
+		it("emits ttft and decode spans for a generating step", async () => {
+			const provider = createFakeProvider([
+				[
+					{ type: "text-delta", delta: "Hello" },
+					{ type: "text-delta", delta: " world" },
+					{ type: "usage", usage: { inputTokens: 10, outputTokens: 5 } },
+					{ type: "finish", reason: "stop" },
+				],
+			]);
+
+			const { logger, sink } = createTestLogger();
+
+			await runTurn({
+				provider,
+				messages: [userMessage],
+				tools: [],
+				dispatch: { maxConcurrent: 1, eager: false },
+				conversationId: "conv-1",
+				turnId: "turn-1",
+				emit: () => {},
+				logger,
+			});
+
+			const ttftOpens = sink.records.filter((r) => r.kind === "span-open" && r.name === "ttft");
+			const ttftCloses = sink.records.filter((r) => r.kind === "span-close" && r.name === "ttft");
+			const decodeOpens = sink.records.filter((r) => r.kind === "span-open" && r.name === "decode");
+			const decodeCloses = sink.records.filter(
+				(r) => r.kind === "span-close" && r.name === "decode",
+			);
+
+			expect(ttftOpens).toHaveLength(1);
+			expect(ttftCloses).toHaveLength(1);
+			expect(decodeOpens).toHaveLength(1);
+			expect(decodeCloses).toHaveLength(1);
+
+			const stepOpen = sink.records.find((r) => r.kind === "span-open" && r.name === "step");
+			expect(stepOpen).toBeDefined();
+
+			if (
+				ttftOpens[0]?.kind === "span-open" &&
+				ttftCloses[0]?.kind === "span-close" &&
+				decodeOpens[0]?.kind === "span-open" &&
+				decodeCloses[0]?.kind === "span-close" &&
+				stepOpen?.kind === "span-open"
+			) {
+				// ttft and decode are children of step
+				expect(ttftOpens[0].parentSpanId).toBe(stepOpen.spanId);
+				expect(decodeOpens[0].parentSpanId).toBe(stepOpen.spanId);
+
+				// ttft closes before decode opens (in order)
+				const ttftCloseIdx = sink.records.indexOf(ttftCloses[0]);
+				const decodeOpenIdx = sink.records.indexOf(decodeOpens[0]);
+				expect(ttftCloseIdx).toBeLessThan(decodeOpenIdx);
+
+				// ttft has firstToken: true
+				expect(ttftCloses[0].attributes?.firstToken).toBe(true);
+
+				// durations from fake clock
+				expect(ttftCloses[0].durationMs).toBeGreaterThanOrEqual(0);
+				expect(decodeCloses[0].durationMs).toBeGreaterThanOrEqual(0);
+			}
+		});
+
+		it("first token counts a reasoning delta", async () => {
+			const provider = createFakeProvider([
+				[
+					{ type: "reasoning-delta", delta: "thinking..." },
+					{ type: "text-delta", delta: "Hello" },
+					{ type: "usage", usage: { inputTokens: 10, outputTokens: 5 } },
+					{ type: "finish", reason: "stop" },
+				],
+			]);
+
+			const { logger, sink } = createTestLogger();
+
+			await runTurn({
+				provider,
+				messages: [userMessage],
+				tools: [],
+				dispatch: { maxConcurrent: 1, eager: false },
+				conversationId: "conv-1",
+				turnId: "turn-1",
+				emit: () => {},
+				logger,
+			});
+
+			const ttftCloses = sink.records.filter((r) => r.kind === "span-close" && r.name === "ttft");
+			expect(ttftCloses).toHaveLength(1);
+
+			// The ttft span should close at the reasoning delta, not at the text delta
+			if (ttftCloses[0]?.kind === "span-close") {
+				expect(ttftCloses[0].attributes?.firstToken).toBe(true);
+			}
+		});
+
+		it("a step with no content token does not emit a misleading decode", async () => {
+			const provider = createFakeProvider([
+				[
+					{ type: "tool-call", toolCallId: "tc1", toolName: "echo", input: {} },
+					{ type: "finish", reason: "tool-calls" },
+				],
+				[
+					{ type: "text-delta", delta: "done" },
+					{ type: "finish", reason: "stop" },
+				],
+			]);
+
+			const tool = createFakeTool("echo", async () => ({ content: "echoed" }));
+
+			const { logger, sink } = createTestLogger();
+
+			await runTurn({
+				provider,
+				messages: [userMessage],
+				tools: [tool],
+				dispatch: { maxConcurrent: 1, eager: false },
+				conversationId: "conv-1",
+				turnId: "turn-1",
+				emit: () => {},
+				logger,
+			});
+
+			// First step (tool-call-only) should have ttft with firstToken: false and no decode
+			const ttftOpens = sink.records.filter((r) => r.kind === "span-open" && r.name === "ttft");
+			const ttftCloses = sink.records.filter((r) => r.kind === "span-close" && r.name === "ttft");
+			const decodeOpens = sink.records.filter((r) => r.kind === "span-open" && r.name === "decode");
+
+			// There should be 2 ttft opens (one per step) and 2 ttft closes
+			expect(ttftOpens).toHaveLength(2);
+			expect(ttftCloses).toHaveLength(2);
+
+			// First step: tool-call-only, no first token
+			if (ttftCloses[0]?.kind === "span-close") {
+				expect(ttftCloses[0].attributes?.firstToken).toBe(false);
+			}
+
+			// Second step: has text-delta, should have firstToken: true and decode span
+			if (ttftCloses[1]?.kind === "span-close") {
+				expect(ttftCloses[1].attributes?.firstToken).toBe(true);
+			}
+
+			// Only one decode span (for the second step)
+			expect(decodeOpens).toHaveLength(1);
+		});
 	});
 
 	describe("provider logger threading", () => {
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);