98f3a7066e
Renames the `disableDataCollection` flag to the more intuitive and positive `dataCollectionEnabled`.
This change improves code clarity by avoiding double negatives and making the purpose of the flag more direct. The logic has been inverted wherever the flag is used to accommodate the new naming convention.
Using a suffix like `"Enabled"` follows a common convention that improves readability.
- A condition like `if (dataCollectionEnabled)` reads like a natural language sentence ("if data collection is enabled"), which reduces cognitive load.
- Distinguishes the boolean flag (representing a state) from potential functions that would perform an action (e.g., `enableDataCollection()` or `disableDataCollection()`), avoiding ambiguity between checking a value and calling a function.
#750
646 lines
18 KiB
TypeScript
646 lines
18 KiB
TypeScript
/**
|
|
* @license
|
|
* Copyright 2025 Google LLC
|
|
* SPDX-License-Identifier: Apache-2.0
|
|
*/
|
|
|
|
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 {
|
|
logApiRequest,
|
|
logApiResponse,
|
|
logCliConfiguration,
|
|
logUserPrompt,
|
|
logToolCall,
|
|
} 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 { GenerateContentResponseUsageMetadata } from '@google/genai';
|
|
|
|
describe('loggers', () => {
|
|
const mockLogger = {
|
|
emit: vi.fn(),
|
|
};
|
|
|
|
beforeEach(() => {
|
|
vi.spyOn(sdk, 'isTelemetrySdkInitialized').mockReturnValue(true);
|
|
vi.spyOn(logs, 'getLogger').mockReturnValue(mockLogger);
|
|
vi.useFakeTimers();
|
|
vi.setSystemTime(new Date('2025-01-01T00:00:00.000Z'));
|
|
});
|
|
|
|
describe('logCliConfiguration', () => {
|
|
it('should log the cli configuration', () => {
|
|
const mockConfig = {
|
|
getSessionId: () => 'test-session-id',
|
|
getModel: () => 'test-model',
|
|
getEmbeddingModel: () => 'test-embedding-model',
|
|
getSandbox: () => true,
|
|
getCoreTools: () => ['ls', 'read-file'],
|
|
getApprovalMode: () => 'default',
|
|
getContentGeneratorConfig: () => ({
|
|
model: 'test-model',
|
|
apiKey: 'test-api-key',
|
|
authType: AuthType.USE_VERTEX_AI,
|
|
}),
|
|
getTelemetryEnabled: () => true,
|
|
getUsageStatisticsEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => true,
|
|
getFileFilteringRespectGitIgnore: () => true,
|
|
getFileFilteringAllowBuildArtifacts: () => false,
|
|
getDebugMode: () => true,
|
|
getMcpServers: () => ({
|
|
'test-server': {
|
|
command: 'test-command',
|
|
},
|
|
}),
|
|
getQuestion: () => 'test-question',
|
|
getTargetDir: () => 'target-dir',
|
|
getProxy: () => 'http://test.proxy.com:8080',
|
|
} as unknown as Config;
|
|
|
|
const startSessionEvent = new StartSessionEvent(mockConfig);
|
|
logCliConfiguration(mockConfig, startSessionEvent);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'CLI configuration loaded.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_CLI_CONFIG,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
model: 'test-model',
|
|
embedding_model: 'test-embedding-model',
|
|
sandbox_enabled: true,
|
|
core_tools_enabled: 'ls,read-file',
|
|
approval_mode: 'default',
|
|
api_key_enabled: true,
|
|
vertex_ai_enabled: true,
|
|
log_user_prompts_enabled: true,
|
|
file_filtering_respect_git_ignore: true,
|
|
debug_mode: true,
|
|
mcp_servers: 'test-server',
|
|
},
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('logUserPrompt', () => {
|
|
const mockConfig = {
|
|
getSessionId: () => 'test-session-id',
|
|
getTelemetryEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => true,
|
|
getUsageStatisticsEnabled: () => true,
|
|
} as unknown as Config;
|
|
|
|
it('should log a user prompt', () => {
|
|
const event = new UserPromptEvent(11, 'test-prompt');
|
|
|
|
logUserPrompt(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'User prompt. Length: 11.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_USER_PROMPT,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
prompt_length: 11,
|
|
prompt: 'test-prompt',
|
|
},
|
|
});
|
|
});
|
|
|
|
it('should not log prompt if disabled', () => {
|
|
const mockConfig = {
|
|
getSessionId: () => 'test-session-id',
|
|
getTelemetryEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => false,
|
|
getTargetDir: () => 'target-dir',
|
|
getUsageStatisticsEnabled: () => true,
|
|
} as unknown as Config;
|
|
const event = new UserPromptEvent(11, 'test-prompt');
|
|
|
|
logUserPrompt(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'User prompt. Length: 11.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_USER_PROMPT,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
prompt_length: 11,
|
|
},
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('logApiResponse', () => {
|
|
const mockConfig = {
|
|
getSessionId: () => 'test-session-id',
|
|
getTargetDir: () => 'target-dir',
|
|
getUsageStatisticsEnabled: () => true,
|
|
getTelemetryEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => true,
|
|
} as Config;
|
|
|
|
const mockMetrics = {
|
|
recordApiResponseMetrics: vi.fn(),
|
|
recordTokenUsageMetrics: vi.fn(),
|
|
};
|
|
|
|
beforeEach(() => {
|
|
vi.spyOn(metrics, 'recordApiResponseMetrics').mockImplementation(
|
|
mockMetrics.recordApiResponseMetrics,
|
|
);
|
|
vi.spyOn(metrics, 'recordTokenUsageMetrics').mockImplementation(
|
|
mockMetrics.recordTokenUsageMetrics,
|
|
);
|
|
});
|
|
|
|
it('should log an API response with all fields', () => {
|
|
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);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'API response from test-model. Status: 200. Duration: 100ms.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_API_RESPONSE,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
[SemanticAttributes.HTTP_STATUS_CODE]: 200,
|
|
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',
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordApiResponseMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-model',
|
|
100,
|
|
200,
|
|
undefined,
|
|
);
|
|
|
|
expect(mockMetrics.recordTokenUsageMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-model',
|
|
50,
|
|
'output',
|
|
);
|
|
});
|
|
|
|
it('should log an API response with an error', () => {
|
|
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: 200. Duration: 100ms.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
...event,
|
|
'event.name': EVENT_API_RESPONSE,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
'error.message': 'test-error',
|
|
},
|
|
});
|
|
});
|
|
});
|
|
|
|
describe('logApiRequest', () => {
|
|
const mockConfig = {
|
|
getSessionId: () => 'test-session-id',
|
|
getTargetDir: () => 'target-dir',
|
|
getUsageStatisticsEnabled: () => true,
|
|
getTelemetryEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => true,
|
|
} as Config;
|
|
|
|
it('should log an API request with request_text', () => {
|
|
const event = new ApiRequestEvent('test-model', 'This is a test request');
|
|
|
|
logApiRequest(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'API request to test-model.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_API_REQUEST,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
model: 'test-model',
|
|
request_text: 'This is a test request',
|
|
},
|
|
});
|
|
});
|
|
|
|
it('should log an API request without request_text', () => {
|
|
const event = new ApiRequestEvent('test-model');
|
|
|
|
logApiRequest(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'API request to test-model.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_API_REQUEST,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
model: 'test-model',
|
|
},
|
|
});
|
|
});
|
|
});
|
|
|
|
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,
|
|
getUsageStatisticsEnabled: () => true,
|
|
getTelemetryEnabled: () => true,
|
|
getTelemetryLogPromptsEnabled: () => true,
|
|
} as Config;
|
|
|
|
const mockMetrics = {
|
|
recordToolCallMetrics: vi.fn(),
|
|
};
|
|
|
|
beforeEach(() => {
|
|
vi.spyOn(metrics, 'recordToolCallMetrics').mockImplementation(
|
|
mockMetrics.recordToolCallMetrics,
|
|
);
|
|
mockLogger.emit.mockReset();
|
|
});
|
|
|
|
it('should log a tool call with all fields', () => {
|
|
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,
|
|
},
|
|
tool: new EditTool(mockConfig),
|
|
durationMs: 100,
|
|
outcome: ToolConfirmationOutcome.ProceedOnce,
|
|
};
|
|
const event = new ToolCallEvent(call);
|
|
|
|
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': EVENT_TOOL_CALL,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
function_name: 'test-function',
|
|
function_args: JSON.stringify(
|
|
{
|
|
arg1: 'value1',
|
|
arg2: 2,
|
|
},
|
|
null,
|
|
2,
|
|
),
|
|
duration_ms: 100,
|
|
success: true,
|
|
decision: ToolCallDecision.ACCEPT,
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-function',
|
|
100,
|
|
true,
|
|
ToolCallDecision.ACCEPT,
|
|
);
|
|
});
|
|
it('should log a tool call with a reject decision', () => {
|
|
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,
|
|
},
|
|
durationMs: 100,
|
|
outcome: ToolConfirmationOutcome.Cancel,
|
|
};
|
|
const event = new ToolCallEvent(call);
|
|
|
|
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': EVENT_TOOL_CALL,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
function_name: 'test-function',
|
|
function_args: JSON.stringify(
|
|
{
|
|
arg1: 'value1',
|
|
arg2: 2,
|
|
},
|
|
null,
|
|
2,
|
|
),
|
|
duration_ms: 100,
|
|
success: false,
|
|
decision: ToolCallDecision.REJECT,
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-function',
|
|
100,
|
|
false,
|
|
ToolCallDecision.REJECT,
|
|
);
|
|
});
|
|
|
|
it('should log a tool call with a modify decision', () => {
|
|
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,
|
|
},
|
|
outcome: ToolConfirmationOutcome.ModifyWithEditor,
|
|
tool: new EditTool(mockConfig),
|
|
durationMs: 100,
|
|
};
|
|
const event = new ToolCallEvent(call);
|
|
|
|
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': EVENT_TOOL_CALL,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
function_name: 'test-function',
|
|
function_args: JSON.stringify(
|
|
{
|
|
arg1: 'value1',
|
|
arg2: 2,
|
|
},
|
|
null,
|
|
2,
|
|
),
|
|
duration_ms: 100,
|
|
success: true,
|
|
decision: ToolCallDecision.MODIFY,
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-function',
|
|
100,
|
|
true,
|
|
ToolCallDecision.MODIFY,
|
|
);
|
|
});
|
|
|
|
it('should log a tool call without a decision', () => {
|
|
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,
|
|
},
|
|
tool: new EditTool(mockConfig),
|
|
durationMs: 100,
|
|
};
|
|
const event = new ToolCallEvent(call);
|
|
|
|
logToolCall(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'Tool call: test-function. Success: true. Duration: 100ms.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_TOOL_CALL,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
function_name: 'test-function',
|
|
function_args: JSON.stringify(
|
|
{
|
|
arg1: 'value1',
|
|
arg2: 2,
|
|
},
|
|
null,
|
|
2,
|
|
),
|
|
duration_ms: 100,
|
|
success: true,
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-function',
|
|
100,
|
|
true,
|
|
undefined,
|
|
);
|
|
});
|
|
|
|
it('should log a failed tool call with an error', () => {
|
|
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',
|
|
},
|
|
},
|
|
durationMs: 100,
|
|
};
|
|
const event = new ToolCallEvent(call);
|
|
|
|
logToolCall(mockConfig, event);
|
|
|
|
expect(mockLogger.emit).toHaveBeenCalledWith({
|
|
body: 'Tool call: test-function. Success: false. Duration: 100ms.',
|
|
attributes: {
|
|
'session.id': 'test-session-id',
|
|
'event.name': EVENT_TOOL_CALL,
|
|
'event.timestamp': '2025-01-01T00:00:00.000Z',
|
|
function_name: 'test-function',
|
|
function_args: JSON.stringify(
|
|
{
|
|
arg1: 'value1',
|
|
arg2: 2,
|
|
},
|
|
null,
|
|
2,
|
|
),
|
|
duration_ms: 100,
|
|
success: false,
|
|
error: 'test-error',
|
|
'error.message': 'test-error',
|
|
error_type: 'test-error-type',
|
|
'error.type': 'test-error-type',
|
|
},
|
|
});
|
|
|
|
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
|
|
mockConfig,
|
|
'test-function',
|
|
100,
|
|
false,
|
|
undefined,
|
|
);
|
|
});
|
|
});
|
|
});
|