diff --git a/core/src/agents/base_agent.ts b/core/src/agents/base_agent.ts index dbfc60d4f..c2cc767e2 100644 --- a/core/src/agents/base_agent.ts +++ b/core/src/agents/base_agent.ts @@ -10,6 +10,7 @@ import {context, trace} from '@opentelemetry/api'; import {createEvent, Event} from '../events/event.js'; import { + getElapsedS, recordAgentInvocationDuration, recordAgentRequestSize, recordAgentResponseSize, @@ -283,7 +284,7 @@ export abstract class BaseAgent< const startTime = performance.now(); const agentName = this.name; const tally: AgentEventTally = {stepCount: 0}; - let error: Error | undefined; + let error: unknown; try { yield* runAsyncGeneratorWithOtelContext( ctx, @@ -323,12 +324,15 @@ export abstract class BaseAgent< }, ); } catch (e) { - error = e as Error; + error = e; throw e; } finally { span.end(); - const elapsedMs = performance.now() - startTime; - recordAgentInvocationDuration(agentName, elapsedMs, error); + recordAgentInvocationDuration( + agentName, + getElapsedS(span, startTime), + error, + ); recordAgentWorkflowSteps(agentName, tally.stepCount); recordAgentResponseSize(agentName, tally.lastContent); } diff --git a/core/src/agents/functions.ts b/core/src/agents/functions.ts index 05b018c17..380f22579 100644 --- a/core/src/agents/functions.ts +++ b/core/src/agents/functions.ts @@ -21,7 +21,10 @@ import {ToolConfirmation} from '../tools/tool_confirmation.js'; import {logger} from '../utils/logger.js'; import {Context} from './context.js'; -import {recordToolExecutionDuration} from '../telemetry/metrics.js'; +import { + getElapsedS, + recordToolExecutionDuration, +} from '../telemetry/metrics.js'; import { traceMergedToolCalls, tracer, @@ -179,8 +182,10 @@ async function callToolAsync( const startTime = performance.now(); const agentName = toolContext.invocationContext.agent.name; const toolName = tool.name; + // e.g. FunctionTool, matching the gen_ai.tool.type span attribute. + const toolType = tool.constructor.name; return tracer.startActiveSpan(`execute_tool ${tool.name}`, async (span) => { - let error: Error | undefined; + let error: unknown; try { logger.debug(`callToolAsync ${tool.name}`); const result = await tool.runAsync({args, toolContext}); @@ -196,14 +201,15 @@ async function callToolAsync( }); return result; } catch (e) { - error = e as Error; + error = e; throw e; } finally { span.end(); recordToolExecutionDuration( toolName, + toolType, agentName, - performance.now() - startTime, + getElapsedS(span, startTime), error, ); } diff --git a/core/src/agents/llm_agent.ts b/core/src/agents/llm_agent.ts index 66cbb7e47..ba8782022 100644 --- a/core/src/agents/llm_agent.ts +++ b/core/src/agents/llm_agent.ts @@ -37,6 +37,7 @@ import {logger} from '../utils/logger.js'; import {Context} from './context.js'; import { + getElapsedS, recordClientOperationDuration, recordClientTokenUsage, } from '../telemetry/metrics.js'; @@ -1093,7 +1094,7 @@ export class LlmAgent extends BaseAgent { invocationContext.incrementLlmCallCount(); const startTime = performance.now(); let lastResponse: LlmResponse | undefined; - let error: Error | undefined; + let error: unknown; try { const responsesGenerator = llm.generateContentAsync( llmRequest, @@ -1129,18 +1130,21 @@ export class LlmAgent extends BaseAgent { yield alteredLlmResponse ?? llmResponse; } } catch (e) { - error = e as Error; + error = e; throw e; } finally { - const elapsedMs = performance.now() - startTime; - recordClientOperationDuration( - this.name, - elapsedMs, + recordClientOperationDuration({ + agentName: this.name, + elapsedS: getElapsedS(undefined, startTime), llmRequest, - lastResponse, + response: lastResponse, error, - ); - recordClientTokenUsage(this.name, llmRequest, lastResponse); + }); + recordClientTokenUsage({ + agentName: this.name, + llmRequest, + response: lastResponse, + }); } } } diff --git a/core/src/common.ts b/core/src/common.ts index 237332ab3..1e4696b26 100644 --- a/core/src/common.ts +++ b/core/src/common.ts @@ -321,5 +321,4 @@ export * from './artifacts/base_artifact_service.js'; export * from './features/feature_registry.js'; export * from './memory/base_memory_service.js'; export * from './sessions/base_session_service.js'; -export * from './telemetry/metrics.js'; export * from './tools/base_tool.js'; diff --git a/core/src/telemetry/metrics.ts b/core/src/telemetry/metrics.ts index 015265ff6..f5882a453 100644 --- a/core/src/telemetry/metrics.ts +++ b/core/src/telemetry/metrics.ts @@ -4,36 +4,85 @@ * SPDX-License-Identifier: Apache-2.0 */ -import {Content, Part} from '@google/genai'; -import {Histogram, Meter, metrics} from '@opentelemetry/api'; +import {Content} from '@google/genai'; +import { + Attributes, + Histogram, + HrTime, + MeterProvider, + MetricAdvice, + metrics, + Span, +} from '@opentelemetry/api'; import {LlmRequest} from '../models/llm_request.js'; import {LlmResponse} from '../models/llm_response.js'; +import {contentSize} from '../utils/content_size_utils.js'; +import {resolveErrorType} from '../utils/error_utils.js'; import {logger} from '../utils/logger.js'; import {getGoogleLlmVariant, GoogleLLMVariant} from '../utils/variant_utils.js'; import {version} from '../version.js'; +import {TokenUsage} from './token_usage.js'; -let meter: Meter | undefined; -function getMeter(): Meter { - if (!meter) { - meter = metrics.getMeter('gcp.vertex.agent', version); - } - return meter; +const METER_NAME = 'gcp.vertex.agent'; + +const ERROR_TYPE = 'error.type'; +const GEN_AI_AGENT_NAME = 'gen_ai.agent.name'; +const GEN_AI_OPERATION_NAME = 'gen_ai.operation.name'; +const GEN_AI_PROVIDER_NAME = 'gen_ai.provider.name'; +const GEN_AI_REQUEST_MODEL = 'gen_ai.request.model'; +const GEN_AI_RESPONSE_MODEL = 'gen_ai.response.model'; +const GEN_AI_TOKEN_TYPE = 'gen_ai.token.type'; +const GEN_AI_TOOL_NAME = 'gen_ai.tool.name'; +const GEN_AI_TOOL_TYPE = 'gen_ai.tool.type'; + +interface HistogramSpec { + name: string; + unit: string; + description: string; + advice?: MetricAdvice; } /** - * Name, unit and description of every histogram recorded by this module. + * Name, unit, description and bucket advisory of every histogram recorded by + * this module. + * + * The names, units and bucket boundaries are a wire contract shared with + * adk-python, so a dashboard built against one runtime works against the + * other. Do not rename or re-unit them. */ const HISTOGRAMS = { agentInvocationDuration: { - name: 'gen_ai.agent.invocation.duration', - unit: 'ms', + name: 'gen_ai.invoke_agent.duration', + unit: 's', description: 'Duration of agent invocations.', + advice: { + explicitBucketBoundaries: [ + 0.1, 0.2, 0.4, 0.8, 1.6, 3.2, 6.4, 12.8, 25.6, 51.2, 102.4, 204.8, + 409.6, + ], + }, }, toolExecutionDuration: { - name: 'gen_ai.tool.execution.duration', - unit: 'ms', + name: 'gen_ai.execute_tool.duration', + unit: 's', description: 'Duration of tool executions.', + advice: { + explicitBucketBoundaries: [ + 0.01, 0.02, 0.04, 0.08, 0.16, 0.32, 0.64, 1.28, 2.56, 5.12, 10.24, + 20.48, 40.96, 81.92, + ], + }, + }, + clientOperationDuration: { + name: 'gen_ai.client.operation.duration', + unit: 's', + description: 'GenAI operation duration.', + }, + clientTokenUsage: { + name: 'gen_ai.client.token.usage', + unit: '{token}', + description: 'Number of input and output tokens used.', }, agentRequestSize: { name: 'gen_ai.agent.request.size', @@ -50,140 +99,114 @@ const HISTOGRAMS = { unit: '1', description: 'Length of agentic workflow (# of events).', }, - clientOperationDuration: { - name: 'gen_ai.client.operation.duration', - unit: 's', - description: 'Duration of client operations.', - }, - clientTokenUsage: { - name: 'gen_ai.client.token.usage', - unit: '1', - description: 'Token usage of client operations.', - }, -} as const; +} satisfies Record; type HistogramKey = keyof typeof HISTOGRAMS; -const instruments = new Map(); +let cache: + | {provider: MeterProvider; instruments: Map} + | undefined; /** * Returns the histogram for `key`, creating it on first use so that no * instrument is registered until a metric is actually recorded. + * + * Unlike the tracing API, the metrics API has no proxy that re-binds to a + * meter provider installed later: `metrics.getMeterProvider()` resolves to + * whatever is registered at call time, and the no-op provider before that. + * Caching against the provider identity is what lets a provider registered + * after the first recording still receive measurements. */ function histogram(key: HistogramKey): Histogram { - let instrument = instruments.get(key); + const provider = metrics.getMeterProvider(); + if (cache?.provider !== provider) { + cache = {provider, instruments: new Map()}; + } + let instrument = cache.instruments.get(key); if (!instrument) { - const {name, unit, description} = HISTOGRAMS[key]; - instrument = getMeter().createHistogram(name, {unit, description}); - instruments.set(key, instrument); + const spec: HistogramSpec = HISTOGRAMS[key]; + const {name, unit, description, advice} = spec; + instrument = provider + .getMeter(METER_NAME, version) + .createHistogram(name, {unit, description, advice}); + cache.instruments.set(key, instrument); } return instrument; } -const textEncoder = new TextEncoder(); - -function getBase64ByteLength(base64String: string): number { - const len = base64String.length; - let padding = 0; - if (base64String.endsWith('==')) { - padding = 2; - } else if (base64String.endsWith('=')) { - padding = 1; - } - return Math.floor((len * 3) / 4) - padding; -} - /** - * Part fields whose payload is structured rather than text or inline bytes. - * Their wire size is approximated by the size of their JSON encoding. + * Runs a recording, never letting a telemetry failure reach the caller. + * + * @param what Named in the debug log so a swallowed failure is traceable. */ -const STRUCTURED_PART_FIELDS = [ - 'functionCall', - 'functionResponse', - 'fileData', - 'executableCode', - 'codeExecutionResult', -] as const; - -function getPartSize(part: Part): number { - let size = 0; - if (part.text !== undefined && part.text !== null) { - size += textEncoder.encode(part.text).length; - } - if (part.inlineData?.data) { - size += getBase64ByteLength(part.inlineData.data); - } - for (const field of STRUCTURED_PART_FIELDS) { - const payload = part[field]; - if (payload !== undefined && payload !== null) { - size += textEncoder.encode(JSON.stringify(payload)).length; - } +function safeRecord(what: string, record: () => void): void { + try { + record(); + } catch (e) { + logger.debug(`Failed to record ${what}`, e); } - return size; +} + +function getProviderName(): string { + return getGoogleLlmVariant() === GoogleLLMVariant.VERTEX_AI + ? 'vertex_ai' + : 'gemini'; } /** - * Approximate size of `content` in bytes: UTF-8 bytes for text, decoded bytes - * for inline blobs, and the UTF-8 size of the JSON encoding for structured - * parts (function calls and responses, file references, executable code and - * its results). + * Attributes shared by both `gen_ai.client.*` instruments. * - * Structured parts are counted so that a tool-calling turn, whose content is - * often a single `functionCall` part, is not reported as 0 bytes: a dashboard - * cannot tell such a reading apart from an unmeasured response. + * @param responseModel The model that answered, when it is known. The duration + * recorder leaves it out until a response has arrived. */ -function getContentSize(content?: Content | null): number { - if (!content || !content.parts) { - return 0; - } - let size = 0; - for (const part of content.parts) { - size += getPartSize(part); +function clientAttributes( + agentName: string, + llmRequest: LlmRequest, + responseModel?: string, +): Attributes { + const attributes: Attributes = { + [GEN_AI_AGENT_NAME]: agentName, + [GEN_AI_OPERATION_NAME]: 'generate_content', + [GEN_AI_PROVIDER_NAME]: getProviderName(), + }; + if (llmRequest.model) { + attributes[GEN_AI_REQUEST_MODEL] = llmRequest.model; } - return size; -} - -function getProviderName(): string { - try { - return getGoogleLlmVariant() === GoogleLLMVariant.VERTEX_AI - ? 'vertex_ai' - : 'gemini'; - } catch (_e) { - return 'gemini'; + if (responseModel) { + attributes[GEN_AI_RESPONSE_MODEL] = responseModel; } + return attributes; } +/** Records the duration of an agent invocation, in seconds. */ export function recordAgentInvocationDuration( agentName: string, - elapsedMs: number, - error?: Error, + elapsedS: number, + error?: unknown, ): void { - try { - const attributes: Record = { - 'gen_ai.agent.name': agentName, - }; - if (error) { - attributes['error.type'] = error.name || error.constructor.name; + safeRecord('agent invocation duration', () => { + const attributes: Attributes = {[GEN_AI_AGENT_NAME]: agentName}; + if (error !== undefined) { + attributes[ERROR_TYPE] = resolveErrorType(error); } - histogram('agentInvocationDuration').record(elapsedMs, attributes); - } catch (e) { - logger.debug('Failed to record agent invocation duration', e); - } + histogram('agentInvocationDuration').record(elapsedS, attributes); + }); } +/** + * Records the size of an agent's request. + * + * @param userContent The content the invocation was started with, if any. + */ export function recordAgentRequestSize( agentName: string, - userContent?: Content | null, + userContent?: Content, ): void { - try { - const size = getContentSize(userContent); - const attributes = { - 'gen_ai.agent.name': agentName, - }; - histogram('agentRequestSize').record(size, attributes); - } catch (e) { - logger.debug('Failed to record agent request size', e); - } + safeRecord('agent request size', () => { + histogram('agentRequestSize').record(contentSize(userContent), { + [GEN_AI_AGENT_NAME]: agentName, + }); + }); } /** @@ -196,15 +219,11 @@ export function recordAgentResponseSize( agentName: string, responseContent?: Content, ): void { - try { - const size = getContentSize(responseContent); - const attributes = { - 'gen_ai.agent.name': agentName, - }; - histogram('agentResponseSize').record(size, attributes); - } catch (e) { - logger.debug('Failed to record agent response size', e); - } + safeRecord('agent response size', () => { + histogram('agentResponseSize').record(contentSize(responseContent), { + [GEN_AI_AGENT_NAME]: agentName, + }); + }); } /** @@ -217,135 +236,152 @@ export function recordAgentWorkflowSteps( agentName: string, stepCount: number, ): void { - try { - const attributes = { - 'gen_ai.agent.name': agentName, - }; - histogram('agentWorkflowSteps').record(stepCount, attributes); - } catch (e) { - logger.debug('Failed to record agent workflow steps', e); - } + safeRecord('agent workflow steps', () => { + histogram('agentWorkflowSteps').record(stepCount, { + [GEN_AI_AGENT_NAME]: agentName, + }); + }); } +/** Records the duration of a tool execution, in seconds. */ export function recordToolExecutionDuration( toolName: string, + toolType: string, agentName: string, - elapsedMs: number, - error?: Error, + elapsedS: number, + error?: unknown, ): void { - try { - const attributes: Record = { - 'gen_ai.agent.name': agentName, - 'gen_ai.tool.name': toolName, + safeRecord('tool execution duration', () => { + const attributes: Attributes = { + [GEN_AI_AGENT_NAME]: agentName, + [GEN_AI_TOOL_NAME]: toolName, + [GEN_AI_TOOL_TYPE]: toolType, }; - if (error) { - attributes['error.type'] = error.name || error.constructor.name; + if (error !== undefined) { + attributes[ERROR_TYPE] = resolveErrorType(error); } - histogram('toolExecutionDuration').record(elapsedMs, attributes); - } catch (e) { - logger.debug('Failed to record tool execution duration', e); - } + histogram('toolExecutionDuration').record(elapsedS, attributes); + }); } /** - * Records the duration of a call to the model. + * Records the duration of a call to the model, in seconds. * - * @param lastResponse The final response of the call, if one was produced. - * Only the last response carries the model version and token counts of the - * whole call, so intermediate streaming chunks are not needed here. + * @param params.response The last response the call produced, if any. Only the + * last one carries the model version of the whole call. */ -export function recordClientOperationDuration( - agentName: string, - elapsedMs: number, - llmRequest: LlmRequest, - lastResponse?: LlmResponse, - error?: Error, -): void { - try { - const attributes: Record = { - 'gen_ai.agent.name': agentName, - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': getProviderName(), - }; - if (llmRequest.model) { - attributes['gen_ai.request.model'] = llmRequest.model; +export function recordClientOperationDuration(params: { + agentName: string; + elapsedS: number; + llmRequest: LlmRequest; + response?: LlmResponse; + error?: unknown; +}): void { + safeRecord('client operation duration', () => { + const {agentName, elapsedS, llmRequest, response, error} = params; + const attributes = clientAttributes( + agentName, + llmRequest, + response && (response.modelVersion || llmRequest.model), + ); + if (error !== undefined) { + attributes[ERROR_TYPE] = resolveErrorType(error); } - if (lastResponse) { - const responseModel = lastResponse.modelVersion || llmRequest.model; - if (responseModel) { - attributes['gen_ai.response.model'] = responseModel; - } - } - if (error) { - attributes['error.type'] = error.name || error.constructor.name; - } - histogram('clientOperationDuration').record(elapsedMs / 1000.0, attributes); - } catch (e) { - logger.debug('Failed to record client operation duration', e); - } + histogram('clientOperationDuration').record(elapsedS, attributes); + }); } /** - * Records the token usage of a call to the model. + * Records the token usage of a call to the model, split into an `input` and an + * `output` measurement. + * + * Cached content tokens are left out because they are already part of the + * prompt tokens, and the total is left out because the semantic conventions + * ask for the input/output breakdown instead. * - * @param lastResponse The final response of the call, if one was produced. Its - * `usageMetadata` covers the whole call. + * @param params.response The last response the call produced, if any. Usage in + * a streaming response is cumulative, so the last chunk holds the total + * for the whole request and earlier chunks must not be added to it. */ -export function recordClientTokenUsage( - agentName: string, - llmRequest: LlmRequest, - lastResponse?: LlmResponse, -): void { - try { - if (!lastResponse) { +export function recordClientTokenUsage(params: { + agentName: string; + llmRequest: LlmRequest; + response?: LlmResponse; +}): void { + safeRecord('client token usage', () => { + const {agentName, llmRequest, response} = params; + if (!response) { return; } - if (!lastResponse.usageMetadata) { - logger.debug( + if (!response.usageMetadata) { + logger.warn( `Skipping missing token usage metadata for agent ${agentName} and model ${llmRequest.model}`, ); return; } - const promptTokens = lastResponse.usageMetadata.promptTokenCount || 0; - const toolTokens = lastResponse.usageMetadata.toolUsePromptTokenCount || 0; - const inputTokenCount = promptTokens + toolTokens; - - const candidatesTokens = - lastResponse.usageMetadata.candidatesTokenCount || 0; - const thoughtsTokens = lastResponse.usageMetadata.thoughtsTokenCount || 0; - const outputTokenCount = candidatesTokens + thoughtsTokens; - - const responseModel = lastResponse.modelVersion || llmRequest.model; - - const baseAttributes: Record = { - 'gen_ai.agent.name': agentName, - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': getProviderName(), - }; - if (llmRequest.model) { - baseAttributes['gen_ai.request.model'] = llmRequest.model; - } - if (responseModel) { - baseAttributes['gen_ai.response.model'] = responseModel; - } + const tokenUsage = new TokenUsage(response.usageMetadata); + const inputTokenCount = tokenUsage.inputTokenCount ?? 0; + const outputTokenCount = tokenUsage.outputTokenCount ?? 0; + const attributes = clientAttributes( + agentName, + llmRequest, + response.modelVersion || llmRequest.model, + ); if (inputTokenCount > 0) { - const inputAttributes = { - ...baseAttributes, - 'gen_ai.token.type': 'input', - }; - histogram('clientTokenUsage').record(inputTokenCount, inputAttributes); + histogram('clientTokenUsage').record(inputTokenCount, { + ...attributes, + [GEN_AI_TOKEN_TYPE]: 'input', + }); } - if (outputTokenCount > 0) { - const outputAttributes = { - ...baseAttributes, - 'gen_ai.token.type': 'output', - }; - histogram('clientTokenUsage').record(outputTokenCount, outputAttributes); + histogram('clientTokenUsage').record(outputTokenCount, { + ...attributes, + [GEN_AI_TOKEN_TYPE]: 'output', + }); } - } catch (e) { - logger.debug('Failed to record client token usage', e); + }); +} + +/** A span whose implementation records the timings the SDK exposes. */ +interface TimedSpan extends Span { + startTime?: unknown; + endTime?: unknown; +} + +function isHrTime(value: unknown): value is HrTime { + return ( + Array.isArray(value) && + value.length === 2 && + typeof value[0] === 'number' && + typeof value[1] === 'number' + ); +} + +/** + * Returns the duration of an operation in seconds, from one consistent time + * source. + * + * Note: this must be called with an ended span. + * + * @param span The ended span to take the duration from. The API `Span` type + * exposes no timings, so they are read off the SDK implementation when it + * provides them. + * @param fallbackStartMs The start time in milliseconds, as returned by + * `performance.now()`, used when the span carries no readable timings. + */ +export function getElapsedS( + span: Span | undefined, + fallbackStartMs: number, +): number { + const timed: TimedSpan | undefined = span; + if (timed && isHrTime(timed.startTime) && isHrTime(timed.endTime)) { + return ( + timed.endTime[0] - + timed.startTime[0] + + (timed.endTime[1] - timed.startTime[1]) / 1e9 + ); } + return (performance.now() - fallbackStartMs) / 1000; } diff --git a/core/src/utils/content_size_utils.ts b/core/src/utils/content_size_utils.ts new file mode 100644 index 000000000..26f80581a --- /dev/null +++ b/core/src/utils/content_size_utils.ts @@ -0,0 +1,66 @@ +/** + * @license + * Copyright 2026 Google LLC + * SPDX-License-Identifier: Apache-2.0 + */ + +import {Content, Part} from '@google/genai'; + +const textEncoder = new TextEncoder(); + +/** + * Part fields whose payload is structured rather than text or inline bytes. + * Their wire size is approximated by the size of their JSON encoding. + */ +const STRUCTURED_PART_FIELDS = [ + 'functionCall', + 'functionResponse', + 'fileData', + 'executableCode', + 'codeExecutionResult', +] as const; + +/** + * Number of bytes a base64 payload decodes to. + * + * Computed rather than decoded: this module is reachable from the browser + * bundle (`index_web.ts` -> `common.ts`), where `Buffer` is not available. + */ +function base64ByteLength(base64: string): number { + const padding = base64.endsWith('==') ? 2 : base64.endsWith('=') ? 1 : 0; + return Math.floor((base64.length * 3) / 4) - padding; +} + +function partSize(part: Part): number { + let size = 0; + if (part.text !== undefined && part.text !== null) { + size += textEncoder.encode(part.text).length; + } + if (part.inlineData?.data) { + size += base64ByteLength(part.inlineData.data); + } + for (const field of STRUCTURED_PART_FIELDS) { + const payload = part[field]; + if (payload !== undefined && payload !== null) { + size += textEncoder.encode(JSON.stringify(payload)).length; + } + } + return size; +} + +/** + * Approximate size of `content` in bytes: UTF-8 bytes for text, decoded bytes + * for inline blobs, and the UTF-8 size of the JSON encoding for structured + * parts (function calls and responses, file references, executable code and + * its results). + * + * Structured parts are counted so that a tool-calling turn, whose content is + * often a single `functionCall` part, is not reported as 0 bytes: a dashboard + * cannot tell such a reading apart from an unmeasured response. + */ +export function contentSize(content?: Content | null): number { + if (!content?.parts) { + return 0; + } + return content.parts.reduce((total, part) => total + partSize(part), 0); +} diff --git a/core/test/agents/functions_test.ts b/core/test/agents/functions_test.ts index 3928b1bb5..3fb9c544f 100644 --- a/core/test/agents/functions_test.ts +++ b/core/test/agents/functions_test.ts @@ -134,6 +134,7 @@ describe('handleFunctionCallList', () => { }); expect(spy).toHaveBeenCalledWith( 'testTool', + 'FunctionTool', 'test_agent', expect.any(Number), undefined, @@ -335,6 +336,7 @@ describe('handleFunctionCallList', () => { }); expect(spy).toHaveBeenCalledWith( 'errorTool', + 'FunctionTool', 'test_agent', expect.any(Number), expect.any(Error), diff --git a/core/test/agents/llm_agent_test.ts b/core/test/agents/llm_agent_test.ts index 324e7325a..20aee4b7a 100644 --- a/core/test/agents/llm_agent_test.ts +++ b/core/test/agents/llm_agent_test.ts @@ -373,18 +373,18 @@ describe('LlmAgent.callLlm', () => { agent.model = new MockLlm(originalLlmResponse); await callLlmUnderTest(); - expect(spyDuration).toHaveBeenCalledWith( - 'test_agent', - expect.any(Number), + expect(spyDuration).toHaveBeenCalledWith({ + agentName: 'test_agent', + elapsedS: expect.any(Number), llmRequest, - originalLlmResponse, - undefined, - ); - expect(spyTokenUsage).toHaveBeenCalledWith( - 'test_agent', + response: originalLlmResponse, + error: undefined, + }); + expect(spyTokenUsage).toHaveBeenCalledWith({ + agentName: 'test_agent', llmRequest, - originalLlmResponse, - ); + response: originalLlmResponse, + }); }); }); diff --git a/core/test/telemetry/metrics_test.ts b/core/test/telemetry/metrics_test.ts index 44c826fbb..653af6d74 100644 --- a/core/test/telemetry/metrics_test.ts +++ b/core/test/telemetry/metrics_test.ts @@ -4,11 +4,26 @@ * SPDX-License-Identifier: Apache-2.0 */ +import { + MeterProvider as ApiMeterProvider, + metrics, + trace, +} from '@opentelemetry/api'; +import { + DataPoint, + DataPointType, + Histogram, + HistogramMetricData, + MeterProvider, + MetricReader, +} from '@opentelemetry/sdk-metrics'; +import {BasicTracerProvider} from '@opentelemetry/sdk-trace-base'; import {afterEach, beforeEach, describe, expect, it, vi} from 'vitest'; import {LlmRequest} from '../../src/models/llm_request.js'; import {LlmResponse} from '../../src/models/llm_response.js'; import { + getElapsedS, recordAgentInvocationDuration, recordAgentRequestSize, recordAgentResponseSize, @@ -17,543 +32,581 @@ import { recordClientTokenUsage, recordToolExecutionDuration, } from '../../src/telemetry/metrics.js'; -import { - getGoogleLlmVariant, - GoogleLLMVariant, -} from '../../src/utils/variant_utils.js'; - -// Define stable mock histograms at the top level so they survive across tests -const mockHistograms = { - 'gen_ai.agent.invocation.duration': {record: vi.fn()}, - 'gen_ai.tool.execution.duration': {record: vi.fn()}, - 'gen_ai.agent.request.size': {record: vi.fn()}, - 'gen_ai.agent.response.size': {record: vi.fn()}, - 'gen_ai.agent.workflow.steps': {record: vi.fn()}, - 'gen_ai.client.operation.duration': {record: vi.fn()}, - 'gen_ai.client.token.usage': {record: vi.fn()}, -}; - -const mockMeter = { - createHistogram: vi.fn((name: keyof typeof mockHistograms) => { - return mockHistograms[name]; - }), -}; - -vi.mock('@opentelemetry/api', () => { - return { - metrics: { - getMeter: vi.fn(() => mockMeter), - }, - }; +import {logger} from '../../src/utils/logger.js'; + +/** Bucket boundaries the SDK applies when an instrument gives no advisory. */ +const SDK_DEFAULT_BOUNDARIES = [ + 0, 5, 10, 25, 50, 75, 100, 250, 500, 750, 1000, 2500, 5000, 7500, 10000, +]; + +class InMemoryMetricReader extends MetricReader { + protected async onForceFlush(): Promise {} + protected async onShutdown(): Promise {} +} + +let reader: InMemoryMetricReader; +let provider: MeterProvider; + +function installMeterProvider(): MeterProvider { + reader = new InMemoryMetricReader(); + const installed = new MeterProvider({readers: [reader]}); + metrics.disable(); + metrics.setGlobalMeterProvider(installed); + return installed; +} + +async function collectHistograms(): Promise> { + const {resourceMetrics} = await reader.collect(); + const byName = new Map(); + for (const scopeMetric of resourceMetrics.scopeMetrics) { + for (const metric of scopeMetric.metrics) { + if (metric.dataPointType === DataPointType.HISTOGRAM) { + byName.set(metric.descriptor.name, metric); + } + } + } + return byName; +} + +async function collectHistogram(name: string): Promise { + const metric = (await collectHistograms()).get(name); + if (!metric) { + expect.fail(`no measurement recorded for ${name}`); + } + return metric; +} + +async function collectDataPoint(name: string): Promise> { + const metric = await collectHistogram(name); + expect(metric.dataPoints).toHaveLength(1); + return metric.dataPoints[0]; +} + +const llmRequest = (model?: string): LlmRequest => ({ + model, + contents: [], + liveConnectConfig: {}, + toolsDict: {}, }); -vi.mock('../../src/utils/variant_utils.js', () => { - return { - getGoogleLlmVariant: vi.fn(() => 'GEMINI_API'), - GoogleLLMVariant: { - VERTEX_AI: 'VERTEX_AI', - GEMINI_API: 'GEMINI_API', - }, - }; -}); - -describe('Telemetry Metrics Functions', () => { +describe('telemetry metrics', () => { beforeEach(() => { - // Clear call history but keep mock references stable - vi.clearAllMocks(); - vi.mocked(getGoogleLlmVariant).mockReturnValue(GoogleLLMVariant.GEMINI_API); + provider = installMeterProvider(); }); - afterEach(() => { + afterEach(async () => { + await provider.shutdown(); + metrics.disable(); + vi.unstubAllEnvs(); vi.restoreAllMocks(); }); + describe('instrument definitions', () => { + const instruments = [ + { + name: 'gen_ai.invoke_agent.duration', + unit: 's', + description: 'Duration of agent invocations.', + boundaries: [ + 0.1, 0.2, 0.4, 0.8, 1.6, 3.2, 6.4, 12.8, 25.6, 51.2, 102.4, 204.8, + 409.6, + ], + record: () => recordAgentInvocationDuration('an-agent', 1), + }, + { + name: 'gen_ai.execute_tool.duration', + unit: 's', + description: 'Duration of tool executions.', + boundaries: [ + 0.01, 0.02, 0.04, 0.08, 0.16, 0.32, 0.64, 1.28, 2.56, 5.12, 10.24, + 20.48, 40.96, 81.92, + ], + record: () => + recordToolExecutionDuration('a-tool', 'FunctionTool', 'an-agent', 1), + }, + { + name: 'gen_ai.client.operation.duration', + unit: 's', + description: 'GenAI operation duration.', + boundaries: SDK_DEFAULT_BOUNDARIES, + record: () => + recordClientOperationDuration({ + agentName: 'an-agent', + elapsedS: 1, + llmRequest: llmRequest('a-model'), + }), + }, + { + name: 'gen_ai.client.token.usage', + unit: '{token}', + description: 'Number of input and output tokens used.', + boundaries: SDK_DEFAULT_BOUNDARIES, + record: () => + recordClientTokenUsage({ + agentName: 'an-agent', + llmRequest: llmRequest('a-model'), + response: {usageMetadata: {promptTokenCount: 1}}, + }), + }, + { + name: 'gen_ai.agent.request.size', + unit: 'By', + description: 'Size of agent requests.', + boundaries: SDK_DEFAULT_BOUNDARIES, + record: () => + recordAgentRequestSize('an-agent', {parts: [{text: 'x'}]}), + }, + { + name: 'gen_ai.agent.response.size', + unit: 'By', + description: 'Size of agent responses.', + boundaries: SDK_DEFAULT_BOUNDARIES, + record: () => + recordAgentResponseSize('an-agent', {parts: [{text: 'x'}]}), + }, + { + name: 'gen_ai.agent.workflow.steps', + unit: '1', + description: 'Length of agentic workflow (# of events).', + boundaries: SDK_DEFAULT_BOUNDARIES, + record: () => recordAgentWorkflowSteps('an-agent', 1), + }, + ]; + + it.each(instruments)( + 'declares $name with its unit, description and buckets', + async ({name, unit, description, boundaries, record}) => { + record(); + + const metric = await collectHistogram(name); + expect(metric.descriptor.unit).toBe(unit); + expect(metric.descriptor.description).toBe(description); + expect(metric.dataPoints[0].value.buckets.boundaries).toEqual( + boundaries, + ); + }, + ); + }); + describe('recordAgentInvocationDuration', () => { - it('should record agent invocation duration with correct attributes', () => { - recordAgentInvocationDuration('my-agent', 123.45); - expect( - mockHistograms['gen_ai.agent.invocation.duration'].record, - ).toHaveBeenCalledWith(123.45, { - 'gen_ai.agent.name': 'my-agent', - }); - }); + it('records the elapsed seconds against the agent name', async () => { + recordAgentInvocationDuration('test_agent', 1.0); - it('should record agent invocation duration with error.type attribute if error is provided', () => { - const err = new Error('Test error'); - recordAgentInvocationDuration('my-agent', 123.45, err); - expect( - mockHistograms['gen_ai.agent.invocation.duration'].record, - ).toHaveBeenCalledWith(123.45, { - 'gen_ai.agent.name': 'my-agent', - 'error.type': 'Error', - }); + const dataPoint = await collectDataPoint('gen_ai.invoke_agent.duration'); + expect(dataPoint.value.sum).toBe(1.0); + expect(dataPoint.attributes).toEqual({'gen_ai.agent.name': 'test_agent'}); }); - it('should fall back to constructor name if error.name is empty', () => { - const err = new Error('Test error'); - err.name = ''; - recordAgentInvocationDuration('my-agent', 123.45, err); - expect( - mockHistograms['gen_ai.agent.invocation.duration'].record, - ).toHaveBeenCalledWith(123.45, { - 'gen_ai.agent.name': 'my-agent', - 'error.type': 'Error', + it('adds the error type when the invocation failed', async () => { + recordAgentInvocationDuration('test_agent', 1.0, new TypeError('boom')); + + const dataPoint = await collectDataPoint('gen_ai.invoke_agent.duration'); + expect(dataPoint.attributes).toEqual({ + 'gen_ai.agent.name': 'test_agent', + 'error.type': 'TypeError', }); }); - it('should handle errors gracefully when recording fails', () => { - mockHistograms[ - 'gen_ai.agent.invocation.duration' - ].record.mockImplementationOnce(() => { - throw new Error('Recording failed'); - }); - expect(() => { - recordAgentInvocationDuration('my-agent', 123.45); - }).not.toThrow(); + it('falls back to the class name if error.name is empty', async () => { + const error = new TypeError('boom'); + error.name = ''; + recordAgentInvocationDuration('test_agent', 1.0, error); + + const dataPoint = await collectDataPoint('gen_ai.invoke_agent.duration'); + expect(dataPoint.attributes['error.type']).toBe('TypeError'); }); }); describe('recordToolExecutionDuration', () => { - it('should record tool execution duration with correct attributes', () => { - recordToolExecutionDuration('my-tool', 'my-agent', 456.78); - expect( - mockHistograms['gen_ai.tool.execution.duration'].record, - ).toHaveBeenCalledWith(456.78, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.tool.name': 'my-tool', - }); - }); + it('records the tool name, type and agent', async () => { + recordToolExecutionDuration( + 'test_tool', + 'test_tool_type', + 'test_agent', + 0.5, + ); - it('should record tool execution duration with error.type attribute if error is provided', () => { - const err = new TypeError('Test type error'); - recordToolExecutionDuration('my-tool', 'my-agent', 456.78, err); - expect( - mockHistograms['gen_ai.tool.execution.duration'].record, - ).toHaveBeenCalledWith(456.78, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.tool.name': 'my-tool', - 'error.type': 'TypeError', + const dataPoint = await collectDataPoint('gen_ai.execute_tool.duration'); + expect(dataPoint.value.sum).toBe(0.5); + expect(dataPoint.attributes).toEqual({ + 'gen_ai.agent.name': 'test_agent', + 'gen_ai.tool.name': 'test_tool', + 'gen_ai.tool.type': 'test_tool_type', }); }); - it('should fall back to constructor name if error.name is empty', () => { - const err = new TypeError('Test type error'); - err.name = ''; - recordToolExecutionDuration('my-tool', 'my-agent', 456.78, err); - expect( - mockHistograms['gen_ai.tool.execution.duration'].record, - ).toHaveBeenCalledWith(456.78, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.tool.name': 'my-tool', - 'error.type': 'TypeError', - }); - }); + it('adds the error type when the tool failed', async () => { + recordToolExecutionDuration( + 'test_tool', + 'test_tool_type', + 'test_agent', + 0.5, + new TypeError('tool failed'), + ); - it('should handle errors gracefully when recording fails', () => { - mockHistograms[ - 'gen_ai.tool.execution.duration' - ].record.mockImplementationOnce(() => { - throw new Error('Recording failed'); - }); - expect(() => { - recordToolExecutionDuration('my-tool', 'my-agent', 456.78); - }).not.toThrow(); + const dataPoint = await collectDataPoint('gen_ai.execute_tool.duration'); + expect(dataPoint.attributes['error.type']).toBe('TypeError'); }); }); describe('recordAgentRequestSize', () => { - it('should record 0 size for null/undefined content', () => { - recordAgentRequestSize('my-agent', null); - expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(0, { - 'gen_ai.agent.name': 'my-agent', - }); - }); + it('records the request size against the agent name', async () => { + recordAgentRequestSize('my-agent', {parts: [{text: 'Hello World'}]}); - it('should record 0 size for content with no parts', () => { - recordAgentRequestSize('my-agent', {parts: []}); - expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(0, { - 'gen_ai.agent.name': 'my-agent', - }); + const dataPoint = await collectDataPoint('gen_ai.agent.request.size'); + expect(dataPoint.value.sum).toBe(11); + expect(dataPoint.attributes).toEqual({'gen_ai.agent.name': 'my-agent'}); }); - it('should record correct byte size for text content', () => { - recordAgentRequestSize('my-agent', { - parts: [{text: 'Hello World'}], // 11 bytes - }); - expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(11, { - 'gen_ai.agent.name': 'my-agent', - }); - }); + it('records 0 when the invocation carried no content', async () => { + recordAgentRequestSize('my-agent', undefined); - it('should record correct byte size for base64 inlineData', () => { - recordAgentRequestSize('my-agent', { - parts: [{inlineData: {data: 'SGVsbG8=', mimeType: 'text/plain'}}], // "Hello" -> 5 bytes - }); expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(5, { - 'gen_ai.agent.name': 'my-agent', - }); - }); - - it('should record correct byte size for base64 inlineData with padding = 2', () => { - recordAgentRequestSize('my-agent', { - parts: [{inlineData: {data: 'QQ==', mimeType: 'text/plain'}}], // 1 byte - }); - expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(1, { - 'gen_ai.agent.name': 'my-agent', - }); - }); - - it('should record 0 byte size for empty base64 inlineData', () => { - recordAgentRequestSize('my-agent', { - parts: [{inlineData: {data: '', mimeType: 'text/plain'}}], - }); - expect( - mockHistograms['gen_ai.agent.request.size'].record, - ).toHaveBeenCalledWith(0, { - 'gen_ai.agent.name': 'my-agent', - }); - }); - - it('should handle errors gracefully when recording fails', () => { - mockHistograms['gen_ai.agent.request.size'].record.mockImplementationOnce( - () => { - throw new Error('Recording failed'); - }, - ); - expect(() => { - recordAgentRequestSize('my-agent', {parts: [{text: 'Hello'}]}); - }).not.toThrow(); + (await collectDataPoint('gen_ai.agent.request.size')).value.sum, + ).toBe(0); }); }); describe('recordAgentResponseSize', () => { - it('should record 0 size if the agent produced no content', () => { - recordAgentResponseSize('my-agent', undefined); - expect( - mockHistograms['gen_ai.agent.response.size'].record, - ).toHaveBeenCalledWith(0, { - 'gen_ai.agent.name': 'my-agent', - }); - }); + it('records the response size against the agent name', async () => { + recordAgentResponseSize('my-agent', {parts: [{text: 'Second Response'}]}); - it('should record correct byte size for the response content', () => { - recordAgentResponseSize('my-agent', { - parts: [{text: 'Second Response'}], // 15 bytes - }); - expect( - mockHistograms['gen_ai.agent.response.size'].record, - ).toHaveBeenCalledWith(15, { - 'gen_ai.agent.name': 'my-agent', - }); + const dataPoint = await collectDataPoint('gen_ai.agent.response.size'); + expect(dataPoint.value.sum).toBe(15); + expect(dataPoint.attributes).toEqual({'gen_ai.agent.name': 'my-agent'}); }); - it('should record the JSON byte size of a function call part', () => { - recordAgentResponseSize('my-agent', { - // {"name":"fake_tool","args":{}} -> 30 bytes - parts: [{functionCall: {name: 'fake_tool', args: {}}}], - }); - expect( - mockHistograms['gen_ai.agent.response.size'].record, - ).toHaveBeenCalledWith(30, { - 'gen_ai.agent.name': 'my-agent', - }); - }); + it('records 0 if the agent produced no content', async () => { + recordAgentResponseSize('my-agent', undefined); - it('should sum text and structured parts of the same content', () => { - recordAgentResponseSize('my-agent', { - parts: [ - {text: 'Hello'}, // 5 bytes - // {"name":"t","response":{}} -> 26 bytes - {functionResponse: {name: 't', response: {}}}, - ], - }); expect( - mockHistograms['gen_ai.agent.response.size'].record, - ).toHaveBeenCalledWith(31, { - 'gen_ai.agent.name': 'my-agent', - }); - }); - - it('should handle errors gracefully when recording fails', () => { - mockHistograms[ - 'gen_ai.agent.response.size' - ].record.mockImplementationOnce(() => { - throw new Error('Recording failed'); - }); - expect(() => { - recordAgentResponseSize('my-agent', {parts: [{text: 'Hello'}]}); - }).not.toThrow(); + (await collectDataPoint('gen_ai.agent.response.size')).value.sum, + ).toBe(0); }); }); describe('recordAgentWorkflowSteps', () => { - it('should record the given workflow step count', () => { + it('records the given workflow step count', async () => { recordAgentWorkflowSteps('my-agent', 3); - expect( - mockHistograms['gen_ai.agent.workflow.steps'].record, - ).toHaveBeenCalledWith(3, { - 'gen_ai.agent.name': 'my-agent', - }); - }); - it('should handle errors gracefully when recording fails', () => { - mockHistograms[ - 'gen_ai.agent.workflow.steps' - ].record.mockImplementationOnce(() => { - throw new Error('Recording failed'); - }); - expect(() => { - recordAgentWorkflowSteps('my-agent', 0); - }).not.toThrow(); + const dataPoint = await collectDataPoint('gen_ai.agent.workflow.steps'); + expect(dataPoint.value.sum).toBe(3); + expect(dataPoint.attributes).toEqual({'gen_ai.agent.name': 'my-agent'}); }); }); describe('recordClientOperationDuration', () => { - it('should record client operation duration converted to seconds with Gemini provider', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = {modelVersion: 'model-a-v1'}; - recordClientOperationDuration('my-agent', 1500, llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(1.5, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a-v1', + it('records the request and response models', async () => { + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.1, + llmRequest: llmRequest('model-a'), + response: {modelVersion: 'model-a-v1'}, }); - }); - it('should record client operation duration converted to seconds with Vertex AI provider', () => { - vi.mocked(getGoogleLlmVariant).mockReturnValue( - GoogleLLMVariant.VERTEX_AI, + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', ); - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = {modelVersion: 'model-a-v1'}; - recordClientOperationDuration('my-agent', 1500, llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(1.5, { - 'gen_ai.agent.name': 'my-agent', + expect(dataPoint.value.sum).toBe(0.1); + expect(dataPoint.attributes).toEqual({ + 'gen_ai.agent.name': 'test_agent', 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'vertex_ai', + 'gen_ai.provider.name': 'gemini', 'gen_ai.request.model': 'model-a', 'gen_ai.response.model': 'model-a-v1', }); }); - it('should fall back to llmRequest.model if lastResponse.modelVersion is missing', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = {}; - recordClientOperationDuration('my-agent', 1500, llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(1.5, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a', + it('reports vertex_ai when GOOGLE_GENAI_USE_VERTEXAI is set', async () => { + vi.stubEnv('GOOGLE_GENAI_USE_VERTEXAI', 'true'); + + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.1, + llmRequest: llmRequest('model-a'), }); + + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', + ); + expect(dataPoint.attributes['gen_ai.provider.name']).toBe('vertex_ai'); }); - it('should handle getGoogleLlmVariant throwing error', () => { - vi.mocked(getGoogleLlmVariant).mockImplementationOnce(() => { - throw new Error('Variant error'); - }); - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = {modelVersion: 'model-a-v1'}; - recordClientOperationDuration('my-agent', 1500, llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(1.5, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a-v1', + it('falls back to the request model when the response omits it', async () => { + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.1, + llmRequest: llmRequest('model-a'), + response: {}, }); + + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', + ); + expect(dataPoint.attributes['gen_ai.response.model']).toBe('model-a'); }); - it('should handle a missing response and no models', () => { - const llmRequest: LlmRequest = {} as LlmRequest; - recordClientOperationDuration('my-agent', 1500, llmRequest, undefined); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(1.5, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', + it('omits the response model when no response arrived', async () => { + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.1, + llmRequest: llmRequest('model-a'), }); + + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', + ); + expect(dataPoint.attributes).not.toHaveProperty('gen_ai.response.model'); }); - it('should record client operation duration with error', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const err = new Error('LLM Error'); - recordClientOperationDuration( - 'my-agent', - 2000, - llmRequest, - undefined, - err, + it('omits both models when neither is known', async () => { + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.1, + llmRequest: llmRequest(undefined), + response: {}, + }); + + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', ); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(2.0, { - 'gen_ai.agent.name': 'my-agent', + expect(dataPoint.attributes).toEqual({ + 'gen_ai.agent.name': 'test_agent', 'gen_ai.operation.name': 'generate_content', 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'error.type': 'Error', }); }); - it('should fall back to constructor name if error.name is empty', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const err = new Error('LLM Error'); - err.name = ''; - recordClientOperationDuration( - 'my-agent', - 2000, - llmRequest, - undefined, - err, + it('adds the error type when the call failed', async () => { + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 0.2, + llmRequest: llmRequest('model-a'), + error: new TypeError('LLM error'), + }); + + const dataPoint = await collectDataPoint( + 'gen_ai.client.operation.duration', ); - expect( - mockHistograms['gen_ai.client.operation.duration'].record, - ).toHaveBeenCalledWith(2.0, { - 'gen_ai.agent.name': 'my-agent', + expect(dataPoint.attributes['error.type']).toBe('TypeError'); + }); + }); + + describe('recordClientTokenUsage', () => { + const usageResponse: LlmResponse = { + modelVersion: 'test-model-v1', + usageMetadata: { + promptTokenCount: 20, + candidatesTokenCount: 30, + toolUsePromptTokenCount: 5, + thoughtsTokenCount: 10, + }, + }; + + it('splits the usage into an input and an output measurement', async () => { + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + response: usageResponse, + }); + + const metric = await collectHistogram('gen_ai.client.token.usage'); + expect(metric.dataPoints).toHaveLength(2); + const baseAttributes = { + 'gen_ai.agent.name': 'test_agent', 'gen_ai.operation.name': 'generate_content', 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'error.type': 'Error', + 'gen_ai.request.model': 'test-model', + 'gen_ai.response.model': 'test-model-v1', + }; + + const input = metric.dataPoints.find( + (dataPoint) => dataPoint.attributes['gen_ai.token.type'] === 'input', + ); + const output = metric.dataPoints.find( + (dataPoint) => dataPoint.attributes['gen_ai.token.type'] === 'output', + ); + if (!input || !output) { + expect.fail('missing input or output token usage'); + } + // prompt (20) + tool use (5), and candidates (30) + thoughts (10). + expect(input.value.sum).toBe(25); + expect(input.attributes).toEqual({ + ...baseAttributes, + 'gen_ai.token.type': 'input', + }); + expect(output.value.sum).toBe(40); + expect(output.attributes).toEqual({ + ...baseAttributes, + 'gen_ai.token.type': 'output', }); }); - it('should handle errors gracefully when recording fails', () => { - mockHistograms[ - 'gen_ai.client.operation.duration' - ].record.mockImplementationOnce(() => { - throw new Error('Recording failed'); + it('records only the input side when there is no output', async () => { + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + response: {usageMetadata: {promptTokenCount: 10}}, }); - expect(() => { - recordClientOperationDuration('my-agent', 1500, {} as LlmRequest, {}); - }).not.toThrow(); + + const dataPoint = await collectDataPoint('gen_ai.client.token.usage'); + expect(dataPoint.value.sum).toBe(10); + expect(dataPoint.attributes['gen_ai.token.type']).toBe('input'); + expect(dataPoint.attributes['gen_ai.response.model']).toBe('test-model'); }); - }); - describe('recordClientTokenUsage', () => { - it('should skip if no response is provided', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - recordClientTokenUsage('my-agent', llmRequest, undefined); - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).not.toHaveBeenCalled(); + it('records only the output side when there is no input', async () => { + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + response: {usageMetadata: {candidatesTokenCount: 12}}, + }); + + const dataPoint = await collectDataPoint('gen_ai.client.token.usage'); + expect(dataPoint.value.sum).toBe(12); + expect(dataPoint.attributes['gen_ai.token.type']).toBe('output'); }); - it('should skip if usageMetadata is missing in the last response', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - recordClientTokenUsage('my-agent', llmRequest, {}); - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).not.toHaveBeenCalled(); + it('records nothing when there is no response', async () => { + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + }); + + expect((await collectHistograms()).has('gen_ai.client.token.usage')).toBe( + false, + ); }); - it('should record input and output token usage correctly', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = { - modelVersion: 'model-a-v1', - usageMetadata: { - promptTokenCount: 10, - toolUsePromptTokenCount: 5, - candidatesTokenCount: 20, - thoughtsTokenCount: 3, - }, - }; - recordClientTokenUsage('my-agent', llmRequest, lastResponse); + it('warns and records nothing when the usage metadata is missing', async () => { + const warn = vi.spyOn(logger, 'warn').mockImplementation(() => {}); - // Input usage = promptTokenCount (10) + toolUsePromptTokenCount (5) = 15 - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).toHaveBeenCalledWith(15, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a-v1', - 'gen_ai.token.type': 'input', + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + response: {}, }); - // Output usage = candidatesTokenCount (20) + thoughtsTokenCount (3) = 23 - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).toHaveBeenCalledWith(23, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a-v1', - 'gen_ai.token.type': 'output', - }); + expect(warn).toHaveBeenCalledWith( + 'Skipping missing token usage metadata for agent test_agent and model test-model', + ); + expect((await collectHistograms()).has('gen_ai.client.token.usage')).toBe( + false, + ); }); - it('should fall back to llmRequest.model if the response has no modelVersion', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = { - usageMetadata: {promptTokenCount: 10}, - }; - recordClientTokenUsage('my-agent', llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).toHaveBeenCalledWith(10, { - 'gen_ai.agent.name': 'my-agent', - 'gen_ai.operation.name': 'generate_content', - 'gen_ai.provider.name': 'gemini', - 'gen_ai.request.model': 'model-a', - 'gen_ai.response.model': 'model-a', - 'gen_ai.token.type': 'input', + it('records nothing when every count is zero', async () => { + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('test-model'), + response: { + usageMetadata: { + promptTokenCount: 0, + toolUsePromptTokenCount: 0, + candidatesTokenCount: 0, + thoughtsTokenCount: 0, + }, + }, }); + + expect((await collectHistograms()).has('gen_ai.client.token.usage')).toBe( + false, + ); }); + }); - it('should not record if input or output token count is zero', () => { - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = { - usageMetadata: { - promptTokenCount: 0, - toolUsePromptTokenCount: 0, - candidatesTokenCount: 0, - thoughtsTokenCount: 0, - }, - }; - recordClientTokenUsage('my-agent', llmRequest, lastResponse); - expect( - mockHistograms['gen_ai.client.token.usage'].record, - ).not.toHaveBeenCalled(); + describe('meter provider resolution', () => { + it('records against a provider registered after the first call', async () => { + metrics.disable(); + recordAgentInvocationDuration('test_agent', 1.0); + + provider = installMeterProvider(); + recordAgentInvocationDuration('test_agent', 2.0); + + const dataPoint = await collectDataPoint('gen_ai.invoke_agent.duration'); + expect(dataPoint.value.count).toBe(1); + expect(dataPoint.value.sum).toBe(2.0); }); - it('should handle errors gracefully when recording fails', () => { - mockHistograms['gen_ai.client.token.usage'].record.mockImplementationOnce( - () => { - throw new Error('Recording failed'); + it('never throws a telemetry failure at the caller', () => { + const throwingProvider: ApiMeterProvider = { + getMeter() { + throw new Error('meter unavailable'); }, - ); - const llmRequest: LlmRequest = {model: 'model-a'} as LlmRequest; - const lastResponse: LlmResponse = { - usageMetadata: {promptTokenCount: 10}, }; + const debug = vi.spyOn(logger, 'debug').mockImplementation(() => {}); + metrics.disable(); + metrics.setGlobalMeterProvider(throwingProvider); + + expect(() => { + recordAgentInvocationDuration('test_agent', 1.0); + recordToolExecutionDuration('t', 'FunctionTool', 'test_agent', 1.0); + recordAgentRequestSize('test_agent', {parts: [{text: 'x'}]}); + recordAgentResponseSize('test_agent', {parts: [{text: 'x'}]}); + recordAgentWorkflowSteps('test_agent', 1); + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 1.0, + llmRequest: llmRequest('model-a'), + }); + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('model-a'), + response: {usageMetadata: {promptTokenCount: 1}}, + }); + }).not.toThrow(); + expect(debug).toHaveBeenCalledTimes(7); + }); + + it('is a no-op when no meter provider is configured', () => { + metrics.disable(); + expect(() => { - recordClientTokenUsage('my-agent', llmRequest, lastResponse); + recordAgentInvocationDuration('test_agent', 1.0); + recordToolExecutionDuration('t', 'FunctionTool', 'test_agent', 1.0); + recordAgentRequestSize('test_agent', {parts: [{text: 'x'}]}); + recordAgentResponseSize('test_agent', {parts: [{text: 'x'}]}); + recordAgentWorkflowSteps('test_agent', 1); + recordClientOperationDuration({ + agentName: 'test_agent', + elapsedS: 1.0, + llmRequest: llmRequest('model-a'), + }); + recordClientTokenUsage({ + agentName: 'test_agent', + llmRequest: llmRequest('model-a'), + response: {usageMetadata: {promptTokenCount: 1}}, + }); }).not.toThrow(); }); }); }); + +describe('getElapsedS', () => { + it('takes the duration from an ended span, to the nanosecond', () => { + const span = new BasicTracerProvider() + .getTracer('test') + .startSpan('op', {startTime: [10, 500_000_000]}); + span.end([12, 750_000_000]); + + expect(getElapsedS(span, performance.now())).toBeCloseTo(2.25, 9); + }); + + it('falls back to the monotonic clock for a span without timings', () => { + trace.disable(); + const span = trace.getTracer('test').startSpan('op'); + span.end(); + + const elapsed = getElapsedS(span, performance.now() - 1000); + + expect(elapsed).toBeGreaterThanOrEqual(1); + expect(elapsed).toBeLessThan(60); + }); + + it('falls back to the monotonic clock when there is no span', () => { + const elapsed = getElapsedS(undefined, performance.now() - 2000); + + expect(elapsed).toBeGreaterThanOrEqual(2); + expect(elapsed).toBeLessThan(60); + }); +}); diff --git a/core/test/utils/content_size_utils_test.ts b/core/test/utils/content_size_utils_test.ts new file mode 100644 index 000000000..f7ddbd8e6 --- /dev/null +++ b/core/test/utils/content_size_utils_test.ts @@ -0,0 +1,70 @@ +/** + * @license + * Copyright 2026 Google LLC + * SPDX-License-Identifier: Apache-2.0 + */ + +import {describe, expect, it} from 'vitest'; + +import {contentSize} from '../../src/utils/content_size_utils.js'; + +describe('contentSize', () => { + it('measures nothing for absent content', () => { + expect(contentSize(undefined)).toBe(0); + expect(contentSize(null)).toBe(0); + }); + + it('measures nothing for content without parts', () => { + expect(contentSize({})).toBe(0); + expect(contentSize({parts: []})).toBe(0); + }); + + it('measures text in UTF-8 bytes, not characters', () => { + expect(contentSize({parts: [{text: 'Hello World'}]})).toBe(11); + // Four characters, ten UTF-8 bytes. + expect(contentSize({parts: [{text: 'né€😀'}]})).toBe(10); + }); + + it('measures inline data as its decoded byte length', () => { + // 'Hello', one padding character. + expect( + contentSize({ + parts: [{inlineData: {data: 'SGVsbG8=', mimeType: 'text/plain'}}], + }), + ).toBe(5); + // 'A', two padding characters. + expect( + contentSize({ + parts: [{inlineData: {data: 'QQ==', mimeType: 'text/plain'}}], + }), + ).toBe(1); + // 'Hello!', no padding at all. + expect( + contentSize({ + parts: [{inlineData: {data: 'SGVsbG8h', mimeType: 'text/plain'}}], + }), + ).toBe(6); + expect( + contentSize({parts: [{inlineData: {data: '', mimeType: 'text/plain'}}]}), + ).toBe(0); + }); + + it('measures a structured part as its JSON encoding', () => { + // {"name":"fake_tool","args":{}} -> 30 bytes + expect( + contentSize({parts: [{functionCall: {name: 'fake_tool', args: {}}}]}), + ).toBe(30); + }); + + it('sums text and structured parts of the same content', () => { + expect( + contentSize({ + parts: [ + {text: 'Hello'}, // 5 bytes + // {"name":"t","response":{}} -> 26 bytes + {functionResponse: {name: 't', response: {}}}, + ], + }), + ).toBe(31); + }); +}); diff --git a/tests/e2e/telemetry/metrics_e2e_test.ts b/tests/e2e/telemetry/metrics_e2e_test.ts index 4a09bc786..58d657df9 100644 --- a/tests/e2e/telemetry/metrics_e2e_test.ts +++ b/tests/e2e/telemetry/metrics_e2e_test.ts @@ -172,10 +172,10 @@ describe('E2E Telemetry Metrics Integration', () => { } } - // Verify gen_ai.agent.invocation.duration + // Verify gen_ai.invoke_agent.duration const durationPoints = dataPointsOf( metricMap, - 'gen_ai.agent.invocation.duration', + 'gen_ai.invoke_agent.duration', ); expect(durationPoints.length).toBe(1); expect(durationPoints[0].attributes).toEqual({ @@ -264,15 +264,16 @@ describe('E2E Telemetry Metrics Integration', () => { 'gen_ai.token.type': 'output', }); - // Verify gen_ai.tool.execution.duration + // Verify gen_ai.execute_tool.duration const toolDurationPoints = dataPointsOf( metricMap, - 'gen_ai.tool.execution.duration', + 'gen_ai.execute_tool.duration', ); expect(toolDurationPoints.length).toBe(1); expect(toolDurationPoints[0].attributes).toEqual({ 'gen_ai.agent.name': 'metrics_e2e_agent', 'gen_ai.tool.name': 'fake_tool', + 'gen_ai.tool.type': 'FunctionTool', }); }); });