diff options
Diffstat (limited to 'packages/core/src/telemetry/loggers.test.ts')
| -rw-r--r-- | packages/core/src/telemetry/loggers.test.ts | 377 |
1 files changed, 217 insertions, 160 deletions
diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index 3fa9ad1c..2659f398 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -4,14 +4,24 @@ * SPDX-License-Identifier: Apache-2.0 */ -import { ToolConfirmationOutcome } from '../tools/tools.js'; -import { AuthType } from '../core/contentGenerator.js'; +import { + AuthType, + CompletedToolCall, + ContentGeneratorConfig, + EditTool, + ErroredToolCall, + GeminiClient, + ToolConfirmationOutcome, + ToolRegistry, +} from '../index.js'; import { logs } from '@opentelemetry/api-logs'; import { SemanticAttributes } from '@opentelemetry/semantic-conventions'; import { Config } from '../config/config.js'; import { EVENT_API_REQUEST, EVENT_API_RESPONSE, + EVENT_CLI_CONFIG, + EVENT_TOOL_CALL, EVENT_USER_PROMPT, } from './constants.js'; import { @@ -20,13 +30,19 @@ import { logCliConfiguration, logUserPrompt, logToolCall, - ToolCallDecision, - getFinalUsageMetadata, } from './loggers.js'; +import { + ApiRequestEvent, + ApiResponseEvent, + StartSessionEvent, + ToolCallDecision, + ToolCallEvent, + UserPromptEvent, +} from './types.js'; import * as metrics from './metrics.js'; import * as sdk from './sdk.js'; import { vi, describe, beforeEach, it, expect } from 'vitest'; -import { GenerateContentResponse } from '@google/genai'; +import { GenerateContentResponseUsageMetadata } from '@google/genai'; describe('loggers', () => { const mockLogger = { @@ -54,8 +70,11 @@ describe('loggers', () => { apiKey: 'test-api-key', authType: AuthType.USE_VERTEX_AI, }), + getTelemetryEnabled: () => true, + getDisableDataCollection: () => false, getTelemetryLogPromptsEnabled: () => true, getFileFilteringRespectGitIgnore: () => true, + getFileFilteringAllowBuildArtifacts: () => false, getDebugMode: () => true, getMcpServers: () => ({ 'test-server': { @@ -63,15 +82,18 @@ describe('loggers', () => { }, }), getQuestion: () => 'test-question', + getTargetDir: () => 'target-dir', + getProxy: () => 'http://test.proxy.com:8080', } as unknown as Config; - logCliConfiguration(mockConfig); + const startSessionEvent = new StartSessionEvent(mockConfig); + logCliConfiguration(mockConfig, startSessionEvent); expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'CLI configuration loaded.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.config', + 'event.name': EVENT_CLI_CONFIG, 'event.timestamp': '2025-01-01T00:00:00.000Z', model: 'test-model', embedding_model: 'test-embedding-model', @@ -92,14 +114,13 @@ describe('loggers', () => { describe('logUserPrompt', () => { const mockConfig = { getSessionId: () => 'test-session-id', + getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => true, + getDisableDataCollection: () => false, } as unknown as Config; it('should log a user prompt', () => { - const event = { - prompt: 'test-prompt', - prompt_length: 11, - }; + const event = new UserPromptEvent(11, 'test-prompt'); logUserPrompt(mockConfig, event); @@ -118,12 +139,12 @@ describe('loggers', () => { it('should not log prompt if disabled', () => { const mockConfig = { getSessionId: () => 'test-session-id', + getTelemetryEnabled: () => true, getTelemetryLogPromptsEnabled: () => false, + getTargetDir: () => 'target-dir', + getDisableDataCollection: () => false, } as unknown as Config; - const event = { - prompt: 'test-prompt', - prompt_length: 11, - }; + const event = new UserPromptEvent(11, 'test-prompt'); logUserPrompt(mockConfig, event); @@ -142,6 +163,10 @@ describe('loggers', () => { describe('logApiResponse', () => { const mockConfig = { getSessionId: () => 'test-session-id', + getTargetDir: () => 'target-dir', + getDisableDataCollection: () => false, + getTelemetryEnabled: () => true, + getTelemetryLogPromptsEnabled: () => true, } as Config; const mockMetrics = { @@ -159,17 +184,19 @@ describe('loggers', () => { }); it('should log an API response with all fields', () => { - const event = { - model: 'test-model', - status_code: 200, - duration_ms: 100, - input_token_count: 17, - output_token_count: 50, - cached_content_token_count: 10, - thoughts_token_count: 5, - tool_token_count: 2, - response_text: 'test-response', + const usageData: GenerateContentResponseUsageMetadata = { + promptTokenCount: 17, + candidatesTokenCount: 50, + cachedContentTokenCount: 10, + thoughtsTokenCount: 5, + toolUsePromptTokenCount: 2, }; + const event = new ApiResponseEvent( + 'test-model', + 100, + usageData, + 'test-response', + ); logApiResponse(mockConfig, event); @@ -209,22 +236,25 @@ describe('loggers', () => { }); it('should log an API response with an error', () => { - const event = { - model: 'test-model', - duration_ms: 100, - error: 'test-error', - input_token_count: 17, - output_token_count: 50, - cached_content_token_count: 10, - thoughts_token_count: 5, - tool_token_count: 2, - response_text: 'test-response', + const usageData: GenerateContentResponseUsageMetadata = { + promptTokenCount: 17, + candidatesTokenCount: 50, + cachedContentTokenCount: 10, + thoughtsTokenCount: 5, + toolUsePromptTokenCount: 2, }; + const event = new ApiResponseEvent( + 'test-model', + 100, + usageData, + 'test-response', + 'test-error', + ); logApiResponse(mockConfig, event); expect(mockLogger.emit).toHaveBeenCalledWith({ - body: 'API response from test-model. Status: N/A. Duration: 100ms.', + body: 'API response from test-model. Status: 200. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', ...event, @@ -239,13 +269,14 @@ describe('loggers', () => { describe('logApiRequest', () => { const mockConfig = { getSessionId: () => 'test-session-id', + getTargetDir: () => 'target-dir', + getDisableDataCollection: () => false, + getTelemetryEnabled: () => true, + getTelemetryLogPromptsEnabled: () => true, } as Config; it('should log an API request with request_text', () => { - const event = { - model: 'test-model', - request_text: 'This is a test request', - }; + const event = new ApiRequestEvent('test-model', 'This is a test request'); logApiRequest(mockConfig, event); @@ -262,9 +293,7 @@ describe('loggers', () => { }); it('should log an API request without request_text', () => { - const event = { - model: 'test-model', - }; + const event = new ApiRequestEvent('test-model'); logApiRequest(mockConfig, event); @@ -281,8 +310,46 @@ describe('loggers', () => { }); describe('logToolCall', () => { + const cfg1 = { + getSessionId: () => 'test-session-id', + getTargetDir: () => 'target-dir', + getGeminiClient: () => mockGeminiClient, + } as Config; + const cfg2 = { + getSessionId: () => 'test-session-id', + getTargetDir: () => 'target-dir', + getProxy: () => 'http://test.proxy.com:8080', + getContentGeneratorConfig: () => + ({ model: 'test-model' }) as ContentGeneratorConfig, + getModel: () => 'test-model', + getEmbeddingModel: () => 'test-embedding-model', + getWorkingDir: () => 'test-working-dir', + getSandbox: () => true, + getCoreTools: () => ['ls', 'read-file'], + getApprovalMode: () => 'default', + getTelemetryLogPromptsEnabled: () => true, + getFileFilteringRespectGitIgnore: () => true, + getFileFilteringAllowBuildArtifacts: () => false, + getDebugMode: () => true, + getMcpServers: () => ({ + 'test-server': { + command: 'test-command', + }, + }), + getQuestion: () => 'test-question', + getToolRegistry: () => new ToolRegistry(cfg1), + getFullContext: () => false, + getUserMemory: () => 'user-memory', + } as unknown as Config; + + const mockGeminiClient = new GeminiClient(cfg2); const mockConfig = { getSessionId: () => 'test-session-id', + getTargetDir: () => 'target-dir', + getGeminiClient: () => mockGeminiClient, + getDisableDataCollection: () => false, + getTelemetryEnabled: () => true, + getTelemetryLogPromptsEnabled: () => true, } as Config; const mockMetrics = { @@ -297,23 +364,36 @@ describe('loggers', () => { }); it('should log a tool call with all fields', () => { - const event = { - function_name: 'test-function', - function_args: { - arg1: 'value1', - arg2: 2, + const call: CompletedToolCall = { + status: 'success', + request: { + name: 'test-function', + args: { + arg1: 'value1', + arg2: 2, + }, + callId: 'test-call-id', + isClientInitiated: true, + }, + response: { + callId: 'test-call-id', + responseParts: 'test-response', + resultDisplay: undefined, + error: undefined, }, - duration_ms: 100, - success: true, + tool: new EditTool(mockConfig), + durationMs: 100, + outcome: ToolConfirmationOutcome.ProceedOnce, }; + const event = new ToolCallEvent(call); - logToolCall(mockConfig, event, ToolConfirmationOutcome.ProceedOnce); + logToolCall(mockConfig, event); expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Tool call: test-function. Decision: accept. Success: true. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.tool_call', + 'event.name': EVENT_TOOL_CALL, 'event.timestamp': '2025-01-01T00:00:00.000Z', function_name: 'test-function', function_args: JSON.stringify( @@ -339,23 +419,35 @@ describe('loggers', () => { ); }); it('should log a tool call with a reject decision', () => { - const event = { - function_name: 'test-function', - function_args: { - arg1: 'value1', - arg2: 2, + const call: ErroredToolCall = { + status: 'error', + request: { + name: 'test-function', + args: { + arg1: 'value1', + arg2: 2, + }, + callId: 'test-call-id', + isClientInitiated: true, + }, + response: { + callId: 'test-call-id', + responseParts: 'test-response', + resultDisplay: undefined, + error: undefined, }, - duration_ms: 100, - success: false, + durationMs: 100, + outcome: ToolConfirmationOutcome.Cancel, }; + const event = new ToolCallEvent(call); - logToolCall(mockConfig, event, ToolConfirmationOutcome.Cancel); + logToolCall(mockConfig, event); expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Tool call: test-function. Decision: reject. Success: false. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.tool_call', + 'event.name': EVENT_TOOL_CALL, 'event.timestamp': '2025-01-01T00:00:00.000Z', function_name: 'test-function', function_args: JSON.stringify( @@ -382,23 +474,36 @@ describe('loggers', () => { }); it('should log a tool call with a modify decision', () => { - const event = { - function_name: 'test-function', - function_args: { - arg1: 'value1', - arg2: 2, + const call: CompletedToolCall = { + status: 'success', + request: { + name: 'test-function', + args: { + arg1: 'value1', + arg2: 2, + }, + callId: 'test-call-id', + isClientInitiated: true, }, - duration_ms: 100, - success: true, + response: { + callId: 'test-call-id', + responseParts: 'test-response', + resultDisplay: undefined, + error: undefined, + }, + outcome: ToolConfirmationOutcome.ModifyWithEditor, + tool: new EditTool(mockConfig), + durationMs: 100, }; + const event = new ToolCallEvent(call); - logToolCall(mockConfig, event, ToolConfirmationOutcome.ModifyWithEditor); + logToolCall(mockConfig, event); expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Tool call: test-function. Decision: modify. Success: true. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.tool_call', + 'event.name': EVENT_TOOL_CALL, 'event.timestamp': '2025-01-01T00:00:00.000Z', function_name: 'test-function', function_args: JSON.stringify( @@ -425,15 +530,27 @@ describe('loggers', () => { }); it('should log a tool call without a decision', () => { - const event = { - function_name: 'test-function', - function_args: { - arg1: 'value1', - arg2: 2, + const call: CompletedToolCall = { + status: 'success', + request: { + name: 'test-function', + args: { + arg1: 'value1', + arg2: 2, + }, + callId: 'test-call-id', + isClientInitiated: true, + }, + response: { + callId: 'test-call-id', + responseParts: 'test-response', + resultDisplay: undefined, + error: undefined, }, - duration_ms: 100, - success: true, + tool: new EditTool(mockConfig), + durationMs: 100, }; + const event = new ToolCallEvent(call); logToolCall(mockConfig, event); @@ -441,7 +558,7 @@ describe('loggers', () => { body: 'Tool call: test-function. Success: true. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.tool_call', + 'event.name': EVENT_TOOL_CALL, 'event.timestamp': '2025-01-01T00:00:00.000Z', function_name: 'test-function', function_args: JSON.stringify( @@ -467,17 +584,29 @@ describe('loggers', () => { }); it('should log a failed tool call with an error', () => { - const event = { - function_name: 'test-function', - function_args: { - arg1: 'value1', - arg2: 2, + const call: ErroredToolCall = { + status: 'error', + request: { + name: 'test-function', + args: { + arg1: 'value1', + arg2: 2, + }, + callId: 'test-call-id', + isClientInitiated: true, + }, + response: { + callId: 'test-call-id', + responseParts: 'test-response', + resultDisplay: undefined, + error: { + name: 'test-error-type', + message: 'test-error', + }, }, - duration_ms: 100, - success: false, - error: 'test-error', - error_type: 'test-error-type', + durationMs: 100, }; + const event = new ToolCallEvent(call); logToolCall(mockConfig, event); @@ -485,7 +614,7 @@ describe('loggers', () => { body: 'Tool call: test-function. Success: false. Duration: 100ms.', attributes: { 'session.id': 'test-session-id', - 'event.name': 'gemini_cli.tool_call', + 'event.name': EVENT_TOOL_CALL, 'event.timestamp': '2025-01-01T00:00:00.000Z', function_name: 'test-function', function_args: JSON.stringify( @@ -515,75 +644,3 @@ describe('loggers', () => { }); }); }); - -describe('getFinalUsageMetadata', () => { - const createMockResponse = ( - usageMetadata?: GenerateContentResponse['usageMetadata'], - ): GenerateContentResponse => - ({ - text: () => '', - data: () => ({}) as Record<string, unknown>, - functionCalls: () => [], - executableCode: () => [], - codeExecutionResult: () => [], - usageMetadata, - }) as unknown as GenerateContentResponse; - - it('should return the usageMetadata from the last chunk that has it', () => { - const chunks: GenerateContentResponse[] = [ - createMockResponse({ - promptTokenCount: 10, - candidatesTokenCount: 20, - totalTokenCount: 30, - }), - createMockResponse(), - createMockResponse({ - promptTokenCount: 15, - candidatesTokenCount: 25, - totalTokenCount: 40, - }), - createMockResponse(), - ]; - - const result = getFinalUsageMetadata(chunks); - expect(result).toEqual({ - promptTokenCount: 15, - candidatesTokenCount: 25, - totalTokenCount: 40, - }); - }); - - it('should return undefined if no chunks have usageMetadata', () => { - const chunks: GenerateContentResponse[] = [ - createMockResponse(), - createMockResponse(), - createMockResponse(), - ]; - - const result = getFinalUsageMetadata(chunks); - expect(result).toBeUndefined(); - }); - - it('should return the metadata from the only chunk if it has it', () => { - const chunks: GenerateContentResponse[] = [ - createMockResponse({ - promptTokenCount: 1, - candidatesTokenCount: 2, - totalTokenCount: 3, - }), - ]; - - const result = getFinalUsageMetadata(chunks); - expect(result).toEqual({ - promptTokenCount: 1, - candidatesTokenCount: 2, - totalTokenCount: 3, - }); - }); - - it('should return undefined for an empty array of chunks', () => { - const chunks: GenerateContentResponse[] = []; - const result = getFinalUsageMetadata(chunks); - expect(result).toBeUndefined(); - }); -}); |
