feat(ai/providers): added duration and TTFT metrics to AI providers
- Added duration and TTFT (time to first token) metrics to AssistantMessage interface. - Implemented performance tracking across all AI providers for streaming responses. - Added timing capture in both success and error code paths for comprehensive metrics. - Updated changelog to document new performance tracking capabilities.
This commit is contained in:
@@ -1,6 +1,10 @@
|
||||
# Changelog
|
||||
|
||||
## [Unreleased]
|
||||
### Added
|
||||
|
||||
- Added duration and time-to-first-token (ttft) metrics to all AI provider responses
|
||||
- Added performance tracking for streaming responses across all providers
|
||||
|
||||
## [6.9.0] - 2026-01-21
|
||||
### Removed
|
||||
|
||||
@@ -67,6 +67,9 @@ export const streamBedrock: StreamFunction<"bedrock-converse-stream"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -113,8 +116,10 @@ export const streamBedrock: StreamFunction<"bedrock-converse-stream"> = (
|
||||
}
|
||||
stream.push({ type: "start", partial: output });
|
||||
} else if (item.contentBlockStart) {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
handleContentBlockStart(item.contentBlockStart, blocks, output, stream);
|
||||
} else if (item.contentBlockDelta) {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
handleContentBlockDelta(item.contentBlockDelta, blocks, output, stream);
|
||||
} else if (item.contentBlockStop) {
|
||||
handleContentBlockStop(item.contentBlockStop, blocks, output, stream);
|
||||
@@ -143,6 +148,8 @@ export const streamBedrock: StreamFunction<"bedrock-converse-stream"> = (
|
||||
throw new Error("An unknown error occurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
@@ -152,6 +159,8 @@ export const streamBedrock: StreamFunction<"bedrock-converse-stream"> = (
|
||||
}
|
||||
output.stopReason = options.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = error instanceof Error ? error.message : JSON.stringify(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -140,6 +140,9 @@ export const streamAnthropic: StreamFunction<"anthropic-messages"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -183,6 +186,7 @@ export const streamAnthropic: StreamFunction<"anthropic-messages"> = (
|
||||
output.usage.input + output.usage.output + output.usage.cacheRead + output.usage.cacheWrite;
|
||||
calculateCost(model, output.usage);
|
||||
} else if (event.type === "content_block_start") {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
if (event.content_block.type === "text") {
|
||||
const block: Block = {
|
||||
type: "text",
|
||||
@@ -321,12 +325,16 @@ export const streamAnthropic: StreamFunction<"anthropic-messages"> = (
|
||||
throw new Error("An unkown error ocurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
for (const block of output.content) delete (block as any).index;
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -294,6 +294,9 @@ export const streamCursor: StreamFunction<"cursor-agent"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -369,6 +372,9 @@ export const streamCursor: StreamFunction<"cursor-agent"> = (
|
||||
get currentToolCall() {
|
||||
return currentToolCall;
|
||||
},
|
||||
get firstTokenTime() {
|
||||
return firstTokenTime;
|
||||
},
|
||||
setTextBlock: (b) => {
|
||||
currentTextBlock = b;
|
||||
},
|
||||
@@ -378,6 +384,9 @@ export const streamCursor: StreamFunction<"cursor-agent"> = (
|
||||
setToolCall: (t) => {
|
||||
currentToolCall = t;
|
||||
},
|
||||
setFirstTokenTime: () => {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
},
|
||||
};
|
||||
|
||||
const onConversationCheckpoint = (checkpoint: ConversationStateStructure) => {
|
||||
@@ -502,6 +511,8 @@ export const streamCursor: StreamFunction<"cursor-agent"> = (
|
||||
|
||||
calculateCost(model, output.usage);
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({
|
||||
type: "done",
|
||||
reason: output.stopReason as "stop" | "length" | "toolUse",
|
||||
@@ -511,6 +522,8 @@ export const streamCursor: StreamFunction<"cursor-agent"> = (
|
||||
} catch (error) {
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
} finally {
|
||||
@@ -532,9 +545,11 @@ interface BlockState {
|
||||
currentTextBlock: (TextContent & { index: number }) | null;
|
||||
currentThinkingBlock: (ThinkingContent & { index: number }) | null;
|
||||
currentToolCall: ToolCallState | null;
|
||||
firstTokenTime: number | undefined;
|
||||
setTextBlock: (b: (TextContent & { index: number }) | null) => void;
|
||||
setThinkingBlock: (b: (ThinkingContent & { index: number }) | null) => void;
|
||||
setToolCall: (t: ToolCallState | null) => void;
|
||||
setFirstTokenTime: () => void;
|
||||
}
|
||||
|
||||
interface UsageState {
|
||||
@@ -1645,6 +1660,7 @@ function processInteractionUpdate(
|
||||
log("interactionUpdate", updateCase, update.message?.value);
|
||||
|
||||
if (updateCase === "textDelta") {
|
||||
state.setFirstTokenTime();
|
||||
const delta = update.message.value.text || "";
|
||||
if (!state.currentTextBlock) {
|
||||
const block: TextContent & { index: number } = {
|
||||
@@ -1660,6 +1676,7 @@ function processInteractionUpdate(
|
||||
const idx = output.content.indexOf(state.currentTextBlock!);
|
||||
stream.push({ type: "text_delta", contentIndex: idx, delta, partial: output });
|
||||
} else if (updateCase === "thinkingDelta") {
|
||||
state.setFirstTokenTime();
|
||||
const delta = update.message.value.text || "";
|
||||
if (!state.currentThinkingBlock) {
|
||||
const block: ThinkingContent & { index: number } = {
|
||||
|
||||
@@ -365,6 +365,9 @@ export const streamGoogleGeminiCli: StreamFunction<"google-gemini-cli"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -489,6 +492,7 @@ export const streamGoogleGeminiCli: StreamFunction<"google-gemini-cli"> = (
|
||||
let started = false;
|
||||
const ensureStarted = () => {
|
||||
if (!started) {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
stream.push({ type: "start", partial: output });
|
||||
started = true;
|
||||
}
|
||||
@@ -802,6 +806,8 @@ export const streamGoogleGeminiCli: StreamFunction<"google-gemini-cli"> = (
|
||||
throw new Error("An unknown error occurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
@@ -812,6 +818,8 @@ export const streamGoogleGeminiCli: StreamFunction<"google-gemini-cli"> = (
|
||||
}
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = error instanceof Error ? error.message : JSON.stringify(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -62,6 +62,9 @@ export const streamGoogleVertex: StreamFunction<"google-vertex"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -97,6 +100,7 @@ export const streamGoogleVertex: StreamFunction<"google-vertex"> = (
|
||||
if (candidate?.content?.parts) {
|
||||
for (const part of candidate.content.parts) {
|
||||
if (part.text !== undefined) {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
const isThinking = isThinkingPart(part);
|
||||
if (
|
||||
!currentBlock ||
|
||||
@@ -258,6 +262,8 @@ export const streamGoogleVertex: StreamFunction<"google-vertex"> = (
|
||||
throw new Error("An unknown error occurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
@@ -269,6 +275,8 @@ export const streamGoogleVertex: StreamFunction<"google-vertex"> = (
|
||||
}
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -53,6 +53,9 @@ export const streamGoogle: StreamFunction<"google-generative-ai"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -88,6 +91,7 @@ export const streamGoogle: StreamFunction<"google-generative-ai"> = (
|
||||
for (const part of candidate.content.parts) {
|
||||
if (part.text !== undefined) {
|
||||
const isThinking = isThinkingPart(part);
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
if (
|
||||
!currentBlock ||
|
||||
(isThinking && currentBlock.type !== "thinking") ||
|
||||
@@ -245,6 +249,8 @@ export const streamGoogle: StreamFunction<"google-generative-ai"> = (
|
||||
throw new Error("An unkown error ocurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
@@ -256,6 +262,8 @@ export const streamGoogle: StreamFunction<"google-generative-ai"> = (
|
||||
}
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -105,6 +105,9 @@ export const streamOpenAICodexResponses: StreamFunction<"openai-codex-responses"
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -225,6 +228,7 @@ export const streamOpenAICodexResponses: StreamFunction<"openai-codex-responses"
|
||||
if (!eventType) continue;
|
||||
|
||||
if (eventType === "response.output_item.added") {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
const item = rawEvent.item as ResponseReasoningItem | ResponseOutputMessage | ResponseFunctionToolCall;
|
||||
if (item.type === "reasoning") {
|
||||
currentItem = item;
|
||||
@@ -412,12 +416,16 @@ export const streamOpenAICodexResponses: StreamFunction<"openai-codex-responses"
|
||||
throw new Error("Codex response failed");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
for (const block of output.content) delete (block as { index?: number }).index;
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -81,6 +81,9 @@ export const streamOpenAICompletions: StreamFunction<"openai-completions"> = (
|
||||
const stream = new AssistantMessageEventStream();
|
||||
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -178,6 +181,7 @@ export const streamOpenAICompletions: StreamFunction<"openai-completions"> = (
|
||||
choice.delta.content !== undefined &&
|
||||
choice.delta.content.length > 0
|
||||
) {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
if (!currentBlock || currentBlock.type !== "text") {
|
||||
finishCurrentBlock(currentBlock);
|
||||
currentBlock = { type: "text", text: "" };
|
||||
@@ -303,6 +307,8 @@ export const streamOpenAICompletions: StreamFunction<"openai-completions"> = (
|
||||
throw new Error("An unkown error ocurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
@@ -312,6 +318,8 @@ export const streamOpenAICompletions: StreamFunction<"openai-completions"> = (
|
||||
// Some providers via OpenRouter include extra details here.
|
||||
const rawMetadata = (error as { error?: { metadata?: { raw?: string } } })?.error?.metadata?.raw;
|
||||
if (rawMetadata) output.errorMessage += `\n${rawMetadata}`;
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -69,6 +69,9 @@ export const streamOpenAIResponses: StreamFunction<"openai-responses"> = (
|
||||
|
||||
// Start async processing
|
||||
(async () => {
|
||||
const startTime = Date.now();
|
||||
let firstTokenTime: number | undefined;
|
||||
|
||||
const output: AssistantMessage = {
|
||||
role: "assistant",
|
||||
content: [],
|
||||
@@ -107,6 +110,7 @@ export const streamOpenAIResponses: StreamFunction<"openai-responses"> = (
|
||||
for await (const event of openaiStream) {
|
||||
// Handle output item start
|
||||
if (event.type === "response.output_item.added") {
|
||||
if (!firstTokenTime) firstTokenTime = Date.now();
|
||||
const item = event.item;
|
||||
if (item.type === "reasoning") {
|
||||
currentItem = item;
|
||||
@@ -309,12 +313,16 @@ export const streamOpenAIResponses: StreamFunction<"openai-responses"> = (
|
||||
throw new Error("An unkown error ocurred");
|
||||
}
|
||||
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "done", reason: output.stopReason, message: output });
|
||||
stream.end();
|
||||
} catch (error) {
|
||||
for (const block of output.content) delete (block as any).index;
|
||||
output.stopReason = options?.signal?.aborted ? "aborted" : "error";
|
||||
output.errorMessage = formatErrorMessageWithRetryAfter(error);
|
||||
output.duration = Date.now() - startTime;
|
||||
if (firstTokenTime) output.ttft = firstTokenTime - startTime;
|
||||
stream.push({ type: "error", reason: output.stopReason, error: output });
|
||||
stream.end();
|
||||
}
|
||||
|
||||
@@ -193,6 +193,8 @@ export interface AssistantMessage {
|
||||
stopReason: StopReason;
|
||||
errorMessage?: string;
|
||||
timestamp: number; // Unix timestamp in milliseconds
|
||||
duration?: number; // Request duration in milliseconds
|
||||
ttft?: number; // Time to first token in milliseconds
|
||||
}
|
||||
|
||||
export interface ToolResultMessage<TDetails = any, TInput = unknown> {
|
||||
|
||||
Reference in New Issue
Block a user