From 287c287ba2a63024025ffd6b42060293b6ef57f4 Mon Sep 17 00:00:00 2001 From: akash-vijay-kv Date: Fri, 12 Jun 2026 13:37:34 +0530 Subject: [PATCH 1/2] [NET-1093] feat: Add TTFT and RTTFT attributes in LLM spans --- package-lock.json | 4 +- package.json | 4 +- src/instrumentation/anthropic/wrappers.ts | 14 ++++- src/instrumentation/google-genai/wrappers.ts | 22 ++----- src/instrumentation/groq/wrappers.ts | 16 +++++- src/instrumentation/mistralai/wrappers.ts | 24 +++++++- src/instrumentation/openai/wrappers.ts | 21 ++++++- src/instrumentation/span-attributes.ts | 4 ++ src/instrumentation/utils.ts | 60 ++++++++++++++++++++ 9 files changed, 144 insertions(+), 25 deletions(-) diff --git a/package-lock.json b/package-lock.json index 8360f0d..1643a99 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "netra-sdk", - "version": "1.1.0-beta", + "version": "1.1.0", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "netra-sdk", - "version": "1.1.0-beta", + "version": "1.1.0", "license": "Apache-2.0", "dependencies": { "@opentelemetry/api": "^1.9.0", diff --git a/package.json b/package.json index 71bd728..c717325 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "netra-sdk", - "version": "1.1.0-beta.1", + "version": "1.1.0", "description": "A comprehensive TypeScript/JavaScript SDK for AI application observability built on top of OpenTelemetry and Traceloop", "type": "module", "main": "./dist/index.cjs", @@ -65,7 +65,7 @@ "@langchain/ollama": "^1.2.1", "@mistralai/mistralai": ">=1.0.0", "@google/generative-ai": "^0.24.1", - "@opentelemetry/instrumentation": ">=0.200.0", + "@opentelemetry/instrumentation": ">=0.53.0", "@opentelemetry/instrumentation-express": "^0.40.0", "@opentelemetry/instrumentation-http": "^0.52.1", "@opentelemetry/instrumentation-undici": "^0.6.0", diff --git a/src/instrumentation/anthropic/wrappers.ts b/src/instrumentation/anthropic/wrappers.ts index 2236419..a5b5f0d 100644 --- a/src/instrumentation/anthropic/wrappers.ts +++ b/src/instrumentation/anthropic/wrappers.ts @@ -1,6 +1,6 @@ import { context, Span, SpanKind, SpanStatusCode, trace, Tracer } from "@opentelemetry/api"; import { Logger } from "../../logger"; -import { defineHidden, isPromise, modelAsDict, shouldSuppressInstrumentation } from "../utils"; +import { defineHidden, isPromise, modelAsDict, recordTTFTAttributes, shouldSuppressInstrumentation } from "../utils"; import { setRequestAttributes, setResponseAttributes } from "./utils"; type AnthropicRequestType = "chat" | "beta" | "batches"; @@ -109,6 +109,7 @@ function anthropicWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -164,6 +165,7 @@ function anthropicWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -216,6 +218,7 @@ export class MessageStreamWrapper { model: "", usage: {}, }; + private firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) private span!: Span; private messageStream!: any; @@ -403,6 +406,10 @@ export class MessageStreamWrapper { ]; if (lastBlock && chunk.delta?.text) { + if (!this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } lastBlock.text += chunk.delta.text; } break; @@ -466,6 +473,7 @@ export class AsyncStreamingWrapper choices: [], model: "", }; + private firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) private span!: Span; private response!: any; @@ -552,6 +560,10 @@ export class AsyncStreamingWrapper const lastBlock = content[content.length - 1]; if (lastBlock && chunk.delta?.text) { + if (!this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } lastBlock.text += chunk.delta.text; } break; diff --git a/src/instrumentation/google-genai/wrappers.ts b/src/instrumentation/google-genai/wrappers.ts index 04a8797..3f26759 100644 --- a/src/instrumentation/google-genai/wrappers.ts +++ b/src/instrumentation/google-genai/wrappers.ts @@ -9,6 +9,7 @@ import { Logger } from "../../logger"; import { isPromise, modelAsDict, + recordTTFTAttributes, shouldSuppressInstrumentation, } from "../utils"; import { setRequestAttributes, setResponseAttributes } from "./utils"; @@ -64,12 +65,8 @@ function googleGenAIWrapper( const endTime = Date.now(); const responseDict = modelAsDict(value); setResponseAttributes(span, responseDict); - const duration = (endTime - startTime) / 1000; - span.setAttribute("llm.response.duration", duration); - span.setAttribute( - "gen_ai.performance.time_to_first_token", - duration, - ); + span.setAttribute("llm.response.duration", (endTime - startTime) / 1000); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -177,12 +174,8 @@ function googleGenAIStreamWrapper( const endTime = Date.now(); const responseDict = modelAsDict(streamResult); setResponseAttributes(span, responseDict); - const duration = (endTime - startTime) / 1000; - span.setAttribute("llm.response.duration", duration); - span.setAttribute( - "gen_ai.performance.time_to_first_token", - duration, - ); + span.setAttribute("llm.response.duration", (endTime - startTime) / 1000); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return streamResult; @@ -247,11 +240,8 @@ function googleGenAIStreamWrapper( : chunk?.text; if (typeof t === "string") { if (t && !firstTokenRecorded) { - span.setAttribute( - "gen_ai.performance.time_to_first_token", - (Date.now() - startTime) / 1000, - ); firstTokenRecorded = true; + recordTTFTAttributes(span, startTime, Date.now()); } finalText += t; } diff --git a/src/instrumentation/groq/wrappers.ts b/src/instrumentation/groq/wrappers.ts index 3743f32..f1bd606 100644 --- a/src/instrumentation/groq/wrappers.ts +++ b/src/instrumentation/groq/wrappers.ts @@ -5,6 +5,7 @@ import { defineHidden, modelAsDict, isPromise, + recordTTFTAttributes, shouldSuppressInstrumentation, } from "../utils"; @@ -98,6 +99,7 @@ function groqWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -121,6 +123,7 @@ function groqWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -147,6 +150,7 @@ export const chatWrapper = (tracer: Tracer) => export class StreamingWrapper implements Iterable, Iterator { private iterator: Iterator | null = null; private completeResponse: Record = { choices: [], model: "" }; + private firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) private span!: Span; private response!: any; @@ -220,10 +224,15 @@ export class StreamingWrapper implements Iterable, Iterator { const delta = choice.delta || {}; if (delta?.content) { + const contentPiece = String(delta.content); + if (contentPiece && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } if (!choices[index].message) { choices[index].message = { role: "assistant", content: "" }; } - choices[index].message.content += String(delta.content); + choices[index].message.content += contentPiece; } if (choice.finish_reason) { @@ -276,6 +285,7 @@ export class AsyncStreamingWrapper choices: [], model: "", }; + private firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) private span!: Span; private response!: any; @@ -361,6 +371,10 @@ export class AsyncStreamingWrapper const delta = (choice.delta || {}) as Record; if (typeof delta === "object" && delta.content) { const contentPiece = String(delta.content || ""); + if (contentPiece && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } const choiceEntry = choices[index]; if (!choiceEntry.message) { choiceEntry.message = { role: "assistant", content: "" }; diff --git a/src/instrumentation/mistralai/wrappers.ts b/src/instrumentation/mistralai/wrappers.ts index c904c3d..cd170ae 100644 --- a/src/instrumentation/mistralai/wrappers.ts +++ b/src/instrumentation/mistralai/wrappers.ts @@ -10,7 +10,7 @@ import { context, } from "@opentelemetry/api"; import { Logger } from "../../logger"; -import { defineHidden, isPromise } from "../utils"; +import { defineHidden, isPromise, recordTTFTAttributes } from "../utils"; import { modelAsDict, setRequestAttributes, @@ -67,6 +67,7 @@ function mistralWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -90,6 +91,7 @@ function mistralWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); + recordTTFTAttributes(span, startTime, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -240,6 +242,7 @@ export class StreamingWrapper implements Iterable, Iterator { choices: [], model: "", }; + private firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) private span!: Span; private response!: unknown; @@ -316,6 +319,13 @@ export class StreamingWrapper implements Iterable, Iterator { } } + private recordFirstToken(contentPiece: string): void { + if (contentPiece && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } + } + private processChunk(chunk: unknown): void { const chunkDict = modelAsDict(chunk); const choices = this.completeResponse.choices as Array< @@ -344,6 +354,7 @@ export class StreamingWrapper implements Iterable, Iterator { const delta = (choice.delta || {}) as Record; if (typeof delta === "object" && delta.content) { const contentPiece = String(delta.content || ""); + this.recordFirstToken(contentPiece); const choiceEntry = choices[index]; if (this.isChat()) { if (!choiceEntry.message) { @@ -379,6 +390,7 @@ export class StreamingWrapper implements Iterable, Iterator { const delta = (choice.delta || {}) as Record; if (typeof delta === "object" && delta.content) { const contentPiece = String(delta.content || ""); + this.recordFirstToken(contentPiece); const choiceEntry = choices[index]; if (this.isChat()) { if (!choiceEntry.message) { @@ -439,6 +451,7 @@ export class AsyncStreamingWrapper private startTime!: number; private requestKwargs!: Record; private completeResponse: Record; + private firstTokenRecorded = false; constructor( span: Span, @@ -534,6 +547,13 @@ export class AsyncStreamingWrapper } } + private recordFirstToken(contentPiece: string): void { + if (contentPiece && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } + } + private processChunk(chunk: unknown): void { const chunkDict = modelAsDict(chunk); const choices = this.completeResponse.choices as Array< @@ -562,6 +582,7 @@ export class AsyncStreamingWrapper const delta = (choice.delta || {}) as Record; if (typeof delta === "object" && delta.content) { const contentPiece = String(delta.content || ""); + this.recordFirstToken(contentPiece); const choiceEntry = choices[index]; if (this.isChat()) { if (!choiceEntry.message) { @@ -597,6 +618,7 @@ export class AsyncStreamingWrapper const delta = (choice.delta || {}) as Record; if (typeof delta === "object" && delta.content) { const contentPiece = String(delta.content || ""); + this.recordFirstToken(contentPiece); const choiceEntry = choices[index]; if (this.isChat()) { if (!choiceEntry.message) { diff --git a/src/instrumentation/openai/wrappers.ts b/src/instrumentation/openai/wrappers.ts index 5a9a455..ea1723f 100644 --- a/src/instrumentation/openai/wrappers.ts +++ b/src/instrumentation/openai/wrappers.ts @@ -11,6 +11,7 @@ import { defineHidden, isPromise, modelAsDict, + recordTTFTAttributes, shouldSuppressInstrumentation, } from "../utils"; import { setRequestAttributes, setResponseAttributes } from "./utils"; @@ -46,14 +47,16 @@ function finalizeSpanSuccess( response: Record, startTime: number, ): void { + const endTime = Date.now(); setResponseAttributes(span, response); - span.setAttribute("llm.response.duration", (Date.now() - startTime) / 1000); + span.setAttribute("llm.response.duration", (endTime - startTime) / 1000); span.setStatus({ code: SpanStatusCode.OK }); span.end(); } abstract class BaseStreamHandler { protected completeResponse: StreamResponse = { choices: [], model: "" }; + protected firstTokenRecorded = false; // Assigned via defineHidden in constructor (non-enumerable to avoid circular JSON) protected span!: Span; protected startTime!: number; @@ -82,17 +85,23 @@ abstract class BaseStreamHandler { const chunkChoices = chunkDict.choices; if (Array.isArray(chunkChoices)) { + console.log("chunkChoices", chunkChoices); for (const choice of chunkChoices as Array>) { const index = Number(choice.index ?? 0); this.ensureChoice(index); const delta = (choice.delta ?? {}) as Record; if (delta.content) { + const contentPiece = String(delta.content); + if (contentPiece && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } const entry = this.completeResponse.choices[index]; if (!entry.message) { entry.message = { role: "assistant", content: "" }; } const msg = entry.message as Record; - msg.content = String(msg.content ?? "") + String(delta.content); + msg.content = String(msg.content ?? "") + contentPiece; } if (choice.finish_reason) { this.completeResponse.choices[index].finish_reason = @@ -128,6 +137,12 @@ abstract class BaseStreamHandler { this.completeResponse.usage = responseChunk.usage ?? {}; } + // Responses API TTFT: trigger on any chunk carrying a delta field + if (chunkDict.delta && !this.firstTokenRecorded) { + this.firstTokenRecorded = true; + recordTTFTAttributes(this.span, this.startTime, Date.now()); + } + this.span.addEvent("llm.content.completion.chunk"); } @@ -317,6 +332,7 @@ function executeNonStreaming( if (isPromise(result)) { return result.then( (value) => { + recordTTFTAttributes(span, startTime, Date.now()); finalizeSpanSuccess(span, modelAsDict(value), startTime); return value; }, @@ -327,6 +343,7 @@ function executeNonStreaming( ); } + recordTTFTAttributes(span, startTime, Date.now()); finalizeSpanSuccess(span, modelAsDict(result), startTime); return result; } catch (error) { diff --git a/src/instrumentation/span-attributes.ts b/src/instrumentation/span-attributes.ts index 867d924..4d7e2c5 100644 --- a/src/instrumentation/span-attributes.ts +++ b/src/instrumentation/span-attributes.ts @@ -26,4 +26,8 @@ export const SpanAttributes = { LLM_IS_STREAMING: "llm.is_streaming", LLM_COMPLETIONS: "gen_ai.completion", LLM_PROMPTS: "gen_ai.prompt", + + LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN: "gen_ai.performance.time_to_first_token", + LLM_PERFORMANCE_RELATIVE_TIME_TO_FIRST_TOKEN: "gen_ai.performance.relative_time_to_first_token", + LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN_TIMESTAMP: "gen_ai.performance.time_to_first_token.timestamp", } as const; diff --git a/src/instrumentation/utils.ts b/src/instrumentation/utils.ts index d1effc0..88eb8ce 100644 --- a/src/instrumentation/utils.ts +++ b/src/instrumentation/utils.ts @@ -4,8 +4,10 @@ */ import { Span, context } from "@opentelemetry/api"; +import { ReadableSpan } from "@opentelemetry/sdk-trace-base"; import { Config } from "../config"; import { Logger } from "../logger"; +import { RootSpanProcessor } from "../processors/root-span-processor"; import { SpanAttributes } from "./span-attributes"; // Suppression @@ -107,6 +109,64 @@ export function hasContent(value: unknown): boolean { return true; } +/** + * Convert an OTel HrTime ([seconds, nanoseconds]) to milliseconds since epoch. + */ +function hrTimeToMs(hrTime: [number, number]): number { + return hrTime[0] * 1000 + hrTime[1] / 1e6; +} + +/** + * Record time-to-first-token and relative-time-to-first-token attributes on a span. + * + * - `gen_ai.performance.time_to_first_token`: seconds from span start (approximated + * by the `startTimeMs` captured at request initiation) to the first token event. + * - `gen_ai.performance.relative_time_to_first_token`: seconds from the root span's + * start time to the first token event. Only set when a root span is found via + * {@link RootSpanProcessor}. + * - `gen_ai.performance.time_to_first_token.timestamp`: UTC ISO 8601 wall-clock + * timestamp of the first token event. + * + * @param span - The active span to annotate. + * @param startTimeMs - `Date.now()` value captured when the LLM request started. + * @param firstTokenTimeMs - `Date.now()` value captured when the first content token arrived. + */ +export function recordTTFTAttributes( + span: Span, + startTimeMs: number, + firstTokenTimeMs: number, +): void { + if (!span.isRecording()) return; + + try { + const ttft = (firstTokenTimeMs - startTimeMs) / 1000; + span.setAttribute( + SpanAttributes.LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN, + String(ttft), + ); + + span.setAttribute( + SpanAttributes.LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN_TIMESTAMP, + new Date(firstTokenTimeMs).toISOString(), + ); + + const rootSpan = RootSpanProcessor.getRootSpan(span); + if (rootSpan) { + const rootStartTime = (rootSpan as unknown as ReadableSpan).startTime; + if (rootStartTime) { + const rootStartMs = hrTimeToMs(rootStartTime as [number, number]); + const relativeTtft = (firstTokenTimeMs - rootStartMs) / 1000; + span.setAttribute( + SpanAttributes.LLM_PERFORMANCE_RELATIVE_TIME_TO_FIRST_TOKEN, + String(relativeTtft), + ); + } + } + } catch (e) { + Logger.debug("recordTTFTAttributes: failed to set TTFT attributes:", e); + } +} + // Attribute Mapping (model params → span attributes) const PARAM_ATTRIBUTE_MAP: Record = { model: SpanAttributes.LLM_REQUEST_MODEL, From 430ae0313cd31f76a75e3271d06eae231d5524ac Mon Sep 17 00:00:00 2001 From: akash-vijay-kv Date: Fri, 12 Jun 2026 13:50:51 +0530 Subject: [PATCH 2/2] fix: Resolved mismatch in TTFT and RTTFT start time --- src/instrumentation/anthropic/wrappers.ts | 8 +++--- src/instrumentation/google-genai/wrappers.ts | 6 ++-- src/instrumentation/groq/wrappers.ts | 8 +++--- src/instrumentation/mistralai/wrappers.ts | 8 +++--- src/instrumentation/openai/wrappers.ts | 8 +++--- src/instrumentation/utils.ts | 30 ++++++++++++-------- 6 files changed, 37 insertions(+), 31 deletions(-) diff --git a/src/instrumentation/anthropic/wrappers.ts b/src/instrumentation/anthropic/wrappers.ts index a5b5f0d..9247146 100644 --- a/src/instrumentation/anthropic/wrappers.ts +++ b/src/instrumentation/anthropic/wrappers.ts @@ -109,7 +109,7 @@ function anthropicWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -165,7 +165,7 @@ function anthropicWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -408,7 +408,7 @@ export class MessageStreamWrapper { if (lastBlock && chunk.delta?.text) { if (!this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } lastBlock.text += chunk.delta.text; } @@ -562,7 +562,7 @@ export class AsyncStreamingWrapper if (lastBlock && chunk.delta?.text) { if (!this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } lastBlock.text += chunk.delta.text; } diff --git a/src/instrumentation/google-genai/wrappers.ts b/src/instrumentation/google-genai/wrappers.ts index 3f26759..48ef883 100644 --- a/src/instrumentation/google-genai/wrappers.ts +++ b/src/instrumentation/google-genai/wrappers.ts @@ -66,7 +66,7 @@ function googleGenAIWrapper( const responseDict = modelAsDict(value); setResponseAttributes(span, responseDict); span.setAttribute("llm.response.duration", (endTime - startTime) / 1000); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -175,7 +175,7 @@ function googleGenAIStreamWrapper( const responseDict = modelAsDict(streamResult); setResponseAttributes(span, responseDict); span.setAttribute("llm.response.duration", (endTime - startTime) / 1000); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return streamResult; @@ -241,7 +241,7 @@ function googleGenAIStreamWrapper( if (typeof t === "string") { if (t && !firstTokenRecorded) { firstTokenRecorded = true; - recordTTFTAttributes(span, startTime, Date.now()); + recordTTFTAttributes(span, Date.now()); } finalText += t; } diff --git a/src/instrumentation/groq/wrappers.ts b/src/instrumentation/groq/wrappers.ts index f1bd606..2ccde92 100644 --- a/src/instrumentation/groq/wrappers.ts +++ b/src/instrumentation/groq/wrappers.ts @@ -99,7 +99,7 @@ function groqWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -123,7 +123,7 @@ function groqWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -227,7 +227,7 @@ export class StreamingWrapper implements Iterable, Iterator { const contentPiece = String(delta.content); if (contentPiece && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } if (!choices[index].message) { choices[index].message = { role: "assistant", content: "" }; @@ -373,7 +373,7 @@ export class AsyncStreamingWrapper const contentPiece = String(delta.content || ""); if (contentPiece && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } const choiceEntry = choices[index]; if (!choiceEntry.message) { diff --git a/src/instrumentation/mistralai/wrappers.ts b/src/instrumentation/mistralai/wrappers.ts index cd170ae..3f0e80e 100644 --- a/src/instrumentation/mistralai/wrappers.ts +++ b/src/instrumentation/mistralai/wrappers.ts @@ -67,7 +67,7 @@ function mistralWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return value; @@ -91,7 +91,7 @@ function mistralWrapper( "llm.response.duration", (endTime - startTime) / 1000 ); - recordTTFTAttributes(span, startTime, endTime); + recordTTFTAttributes(span, endTime); span.setStatus({ code: SpanStatusCode.OK }); span.end(); return response; @@ -322,7 +322,7 @@ export class StreamingWrapper implements Iterable, Iterator { private recordFirstToken(contentPiece: string): void { if (contentPiece && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } } @@ -550,7 +550,7 @@ export class AsyncStreamingWrapper private recordFirstToken(contentPiece: string): void { if (contentPiece && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } } diff --git a/src/instrumentation/openai/wrappers.ts b/src/instrumentation/openai/wrappers.ts index ea1723f..e8ca0c8 100644 --- a/src/instrumentation/openai/wrappers.ts +++ b/src/instrumentation/openai/wrappers.ts @@ -94,7 +94,7 @@ abstract class BaseStreamHandler { const contentPiece = String(delta.content); if (contentPiece && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } const entry = this.completeResponse.choices[index]; if (!entry.message) { @@ -140,7 +140,7 @@ abstract class BaseStreamHandler { // Responses API TTFT: trigger on any chunk carrying a delta field if (chunkDict.delta && !this.firstTokenRecorded) { this.firstTokenRecorded = true; - recordTTFTAttributes(this.span, this.startTime, Date.now()); + recordTTFTAttributes(this.span, Date.now()); } this.span.addEvent("llm.content.completion.chunk"); @@ -332,7 +332,7 @@ function executeNonStreaming( if (isPromise(result)) { return result.then( (value) => { - recordTTFTAttributes(span, startTime, Date.now()); + recordTTFTAttributes(span, Date.now()); finalizeSpanSuccess(span, modelAsDict(value), startTime); return value; }, @@ -343,7 +343,7 @@ function executeNonStreaming( ); } - recordTTFTAttributes(span, startTime, Date.now()); + recordTTFTAttributes(span, Date.now()); finalizeSpanSuccess(span, modelAsDict(result), startTime); return result; } catch (error) { diff --git a/src/instrumentation/utils.ts b/src/instrumentation/utils.ts index 88eb8ce..45eef83 100644 --- a/src/instrumentation/utils.ts +++ b/src/instrumentation/utils.ts @@ -119,31 +119,37 @@ function hrTimeToMs(hrTime: [number, number]): number { /** * Record time-to-first-token and relative-time-to-first-token attributes on a span. * - * - `gen_ai.performance.time_to_first_token`: seconds from span start (approximated - * by the `startTimeMs` captured at request initiation) to the first token event. - * - `gen_ai.performance.relative_time_to_first_token`: seconds from the root span's - * start time to the first token event. Only set when a root span is found via - * {@link RootSpanProcessor}. + * Both durations are derived from the OTel SDK's internal {@link ReadableSpan.startTime} + * (HrTime) so that TTFT and relative TTFT are consistent when the span itself is the + * root span. + * + * - `gen_ai.performance.time_to_first_token`: seconds from the span's own start time + * to the first token event. + * - `gen_ai.performance.relative_time_to_first_token`: seconds from the trace root + * span's start time to the first token event. Only set when a root span is found + * via {@link RootSpanProcessor}. * - `gen_ai.performance.time_to_first_token.timestamp`: UTC ISO 8601 wall-clock * timestamp of the first token event. * * @param span - The active span to annotate. - * @param startTimeMs - `Date.now()` value captured when the LLM request started. * @param firstTokenTimeMs - `Date.now()` value captured when the first content token arrived. */ export function recordTTFTAttributes( span: Span, - startTimeMs: number, firstTokenTimeMs: number, ): void { if (!span.isRecording()) return; try { - const ttft = (firstTokenTimeMs - startTimeMs) / 1000; - span.setAttribute( - SpanAttributes.LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN, - String(ttft), - ); + const spanStartTime = (span as unknown as ReadableSpan).startTime; + if (spanStartTime) { + const spanStartMs = hrTimeToMs(spanStartTime as [number, number]); + const ttft = (firstTokenTimeMs - spanStartMs) / 1000; + span.setAttribute( + SpanAttributes.LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN, + String(ttft), + ); + } span.setAttribute( SpanAttributes.LLM_PERFORMANCE_TIME_TO_FIRST_TOKEN_TIMESTAMP,