* Emit a per-step completion log with the LLM response timing. TTFT is split * into the client-side request-build portion and the network + API-server * portion, and the decode window is split into server (awaiting parts) vs. * client (processing parts) time, so slow turns can be attributed witho
( log: Logger | undefined, turnId: string, step: number, response: LLMChatResponse, )
| 234 | * parsing the wire log. |
| 235 | */ |
| 236 | function logStepTiming( |
| 237 | log: Logger | undefined, |
| 238 | turnId: string, |
| 239 | step: number, |
| 240 | response: LLMChatResponse, |
| 241 | ): void { |
| 242 | if (log === undefined) return; |
| 243 | const timing = response.streamTiming; |
| 244 | if (timing === undefined) return; |
| 245 | log.info('llm response', { |
| 246 | turnStep: `${turnId}/${String(step)}`, |
| 247 | ttftMs: timing.firstTokenLatencyMs, |
| 248 | ...(timing.requestBuildMs !== undefined ? { requestBuildMs: timing.requestBuildMs } : {}), |
| 249 | ...(timing.serverFirstTokenMs !== undefined |
| 250 | ? { serverFirstTokenMs: timing.serverFirstTokenMs } |
| 251 | : {}), |
| 252 | streamDurationMs: timing.streamDurationMs, |
| 253 | ...(timing.serverDecodeMs !== undefined ? { serverDecodeMs: timing.serverDecodeMs } : {}), |
| 254 | ...(timing.clientConsumeMs !== undefined ? { clientConsumeMs: timing.clientConsumeMs } : {}), |
| 255 | outputTokens: response.usage.output, |
| 256 | }); |
| 257 | } |
| 258 | |
| 259 | function deriveStepStopReason(response: LLMChatResponse): LoopStepStopReason { |
| 260 | switch (response.providerFinishReason) { |