abbyswag/qwen-code
1
0
Fork 0
mirror of https://github.com/QwenLM/qwen-code.git synced 2025-12-20 08:47:44 +00:00
Code Issues Packages Projects Releases Wiki Activity

Clearcut logging - initial implementation (#1274)

Browse Source 
Flag-guarded initial implementation of a clearcut logger to collect telemetry data and send it to Concord for dashboards, etc.
This commit is contained in:
owenofbrien
2025-06-22 09:26:48 -05:00
committed by GitHub
parent c9950b3cb2
commit 4cfab0a893
23 changed files with 1051 additions and 335 deletions
Download Patch File Download Diff File Expand all files Collapse all files

377
packages/core/src/telemetry/loggers.test.ts
View File

@@ -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,
},
duration_ms: 100,
success: 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, 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,
},
duration_ms: 100,
success: false,
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, 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,
},
duration_ms: 100,
success: 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);
@@ -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,
},
duration_ms: 100,
success: false,
error: 'test-error',
error_type: 'test-error-type',
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);
@@ -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();
});
});