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

Sync upstream Gemini-CLI v0.8.2 (#838)

Browse Source
This commit is contained in:
tanzhenxin
2025-10-23 09:27:04 +08:00
committed by GitHub
parent 096fabb5d6
commit eb95c131be
644 changed files with 70389 additions and 23709 deletions
Download Patch File Download Diff File Expand all files Collapse all files

219
packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts
View File

@@ -18,19 +18,26 @@ import type { LogEvent, LogEventEntry } from './clearcut-logger.js';
import { ClearcutLogger, EventNames, TEST_ONLY } from './clearcut-logger.js';
import type { ContentGeneratorConfig } from '../../core/contentGenerator.js';
import { AuthType } from '../../core/contentGenerator.js';
import type { SuccessfulToolCall } from '../../core/coreToolScheduler.js';
import type { ConfigParameters } from '../../config/config.js';
import { EventMetadataKey } from './event-metadata-key.js';
import { makeFakeConfig } from '../../test-utils/config.js';
import { http, HttpResponse } from 'msw';
import { server } from '../../mocks/msw.js';
import { UserPromptEvent, makeChatCompressionEvent } from '../types.js';
import {
UserPromptEvent,
makeChatCompressionEvent,
ToolCallEvent,
} from '../types.js';
import { GIT_COMMIT_INFO, CLI_VERSION } from '../../generated/git-commit.js';
import { UserAccountManager } from '../../utils/userAccountManager.js';
import { InstallationManager } from '../../utils/installationManager.js';
import { safeJsonStringify } from '../../utils/safeJsonStringify.js';
interface CustomMatchers<R = unknown> {
toHaveMetadataValue: ([key, value]: [EventMetadataKey, string]) => R;
toHaveEventName: (name: EventNames) => R;
toHaveMetadataKey: (key: EventMetadataKey) => R;
}
declare module 'vitest' {
@@ -67,6 +74,20 @@ expect.extend({
`event ${received} does${isNot ? ' not' : ''} have ${value}}`,
};
},
toHaveMetadataKey(received: LogEventEntry[], key: EventMetadataKey) {
const { isNot } = this;
const event = JSON.parse(received[0].source_extension_json) as LogEvent;
const metadata = event['event_metadata'][0];
const pass = metadata.some((m) => m.gemini_cli_key === key);
return {
pass,
message: () =>
`event ${received} ${isNot ? 'has' : 'does not have'} the metadata key ${key}`,
};
},
});
vi.mock('../../utils/userAccountManager.js');
@@ -199,6 +220,32 @@ describe('ClearcutLogger', () => {
});
});
it('logs the current surface from Cloud Shell via EDITOR_IN_CLOUD_SHELL', () => {
const { logger } = setup({});
vi.stubEnv('EDITOR_IN_CLOUD_SHELL', 'true');
const event = logger?.createLogEvent(EventNames.CHAT_COMPRESSION, []);
expect(event?.event_metadata[0]).toContainEqual({
gemini_cli_key: EventMetadataKey.GEMINI_CLI_SURFACE,
value: 'cloudshell',
});
});
it('logs the current surface from Cloud Shell via CLOUD_SHELL', () => {
const { logger } = setup({});
vi.stubEnv('CLOUD_SHELL', 'true');
const event = logger?.createLogEvent(EventNames.CHAT_COMPRESSION, []);
expect(event?.event_metadata[0]).toContainEqual({
gemini_cli_key: EventMetadataKey.GEMINI_CLI_SURFACE,
value: 'cloudshell',
});
});
it('logs default metadata', () => {
// Define expected values
const session_id = 'my-session-id';
@@ -208,6 +255,7 @@ describe('ClearcutLogger', () => {
const cli_version = CLI_VERSION;
const git_commit_hash = GIT_COMMIT_INFO;
const prompt_id = 'my-prompt-123';
const user_settings = safeJsonStringify([{ smart_edit_enabled: false }]);
// Setup logger with expected values
const { logger, loggerConfig } = setup({
@@ -258,10 +306,25 @@ describe('ClearcutLogger', () => {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_OS,
value: process.platform,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_USER_SETTINGS,
value: user_settings,
},
]),
);
});
it('logs the current nodejs version', () => {
const { logger } = setup({});
const event = logger?.createLogEvent(EventNames.API_ERROR, []);
expect(event?.event_metadata[0]).toContainEqual({
gemini_cli_key: EventMetadataKey.GEMINI_CLI_NODE_VERSION,
value: process.versions.node,
});
});
it('logs the current surface', () => {
const { logger } = setup({});
@@ -372,6 +435,24 @@ describe('ClearcutLogger', () => {
});
});
describe('logRipgrepFallbackEvent', () => {
it('logs an event with the proper name', () => {
const { logger } = setup();
// Spy on flushToClearcut to prevent it from clearing the queue
const flushSpy = vi
// eslint-disable-next-line @typescript-eslint/no-explicit-any
.spyOn(logger!, 'flushToClearcut' as any)
.mockResolvedValue({ nextRequestWaitMs: 0 });
logger?.logRipgrepFallbackEvent();
const events = getEvents(logger!);
expect(events.length).toBe(1);
expect(events[0]).toHaveEventName(EventNames.RIPGREP_FALLBACK);
expect(flushSpy).toHaveBeenCalledOnce();
});
});
describe('enqueueLogEvent', () => {
it('should add events to the queue', () => {
const { logger } = setup();
@@ -557,4 +638,140 @@ describe('ClearcutLogger', () => {
expect(firstRequeuedEvent.event_id).toBe('failed_5');
});
});
describe('logToolCallEvent', () => {
it('logs an event with all diff metadata', () => {
const { logger } = setup();
const completedToolCall = {
request: { name: 'test', args: {}, prompt_id: 'prompt-123' },
response: {
resultDisplay: {
diffStat: {
model_added_lines: 1,
model_removed_lines: 2,
model_added_chars: 3,
model_removed_chars: 4,
user_added_lines: 5,
user_removed_lines: 6,
user_added_chars: 7,
user_removed_chars: 8,
},
},
},
status: 'success',
} as SuccessfulToolCall;
logger?.logToolCallEvent(new ToolCallEvent(completedToolCall));
const events = getEvents(logger!);
expect(events.length).toBe(1);
expect(events[0]).toHaveEventName(EventNames.TOOL_CALL);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
'1',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_REMOVED_LINES,
'2',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_ADDED_CHARS,
'3',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_REMOVED_CHARS,
'4',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_USER_ADDED_LINES,
'5',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_USER_REMOVED_LINES,
'6',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_USER_ADDED_CHARS,
'7',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_USER_REMOVED_CHARS,
'8',
]);
});
it('logs an event with partial diff metadata', () => {
const { logger } = setup();
const completedToolCall = {
request: { name: 'test', args: {}, prompt_id: 'prompt-123' },
response: {
resultDisplay: {
diffStat: {
model_added_lines: 1,
model_removed_lines: 2,
model_added_chars: 3,
model_removed_chars: 4,
},
},
},
status: 'success',
} as SuccessfulToolCall;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
logger?.logToolCallEvent(new ToolCallEvent(completedToolCall as any));
const events = getEvents(logger!);
expect(events.length).toBe(1);
expect(events[0]).toHaveEventName(EventNames.TOOL_CALL);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
'1',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_REMOVED_LINES,
'2',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_ADDED_CHARS,
'3',
]);
expect(events[0]).toHaveMetadataValue([
EventMetadataKey.GEMINI_CLI_AI_REMOVED_CHARS,
'4',
]);
expect(events[0]).not.toHaveMetadataKey(
EventMetadataKey.GEMINI_CLI_USER_ADDED_LINES,
);
expect(events[0]).not.toHaveMetadataKey(
EventMetadataKey.GEMINI_CLI_USER_REMOVED_LINES,
);
expect(events[0]).not.toHaveMetadataKey(
EventMetadataKey.GEMINI_CLI_USER_ADDED_CHARS,
);
expect(events[0]).not.toHaveMetadataKey(
EventMetadataKey.GEMINI_CLI_USER_REMOVED_CHARS,
);
});
it('does not log diff metadata if diffStat is not present', () => {
const { logger } = setup();
const completedToolCall = {
request: { name: 'test', args: {}, prompt_id: 'prompt-123' },
response: {
resultDisplay: {},
},
status: 'success',
} as SuccessfulToolCall;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
logger?.logToolCallEvent(new ToolCallEvent(completedToolCall as any));
const events = getEvents(logger!);
expect(events.length).toBe(1);
expect(events[0]).toHaveEventName(EventNames.TOOL_CALL);
expect(events[0]).not.toHaveMetadataKey(
EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
);
});
});
});

239
packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts
View File

@@ -24,6 +24,12 @@ import type {
InvalidChunkEvent,
ContentRetryEvent,
ContentRetryFailureEvent,
ExtensionInstallEvent,
ToolOutputTruncatedEvent,
ExtensionUninstallEvent,
ExtensionEnableEvent,
ModelSlashCommandEvent,
ExtensionDisableEvent,
} from '../types.js';
import { EventMetadataKey } from './event-metadata-key.js';
import type { Config } from '../../config/config.js';
@@ -32,7 +38,11 @@ import { UserAccountManager } from '../../utils/userAccountManager.js';
import { safeJsonStringify } from '../../utils/safeJsonStringify.js';
import { FixedDeque } from 'mnemonist';
import { GIT_COMMIT_INFO, CLI_VERSION } from '../../generated/git-commit.js';
import { DetectedIde, detectIdeFromEnv } from '../../ide/detect-ide.js';
import {
IDE_DEFINITIONS,
detectIdeFromEnv,
isCloudShell,
} from '../../ide/detect-ide.js';
export enum EventNames {
START_SESSION = 'start_session',
@@ -44,7 +54,9 @@ export enum EventNames {
API_ERROR = 'api_error',
END_SESSION = 'end_session',
FLASH_FALLBACK = 'flash_fallback',
RIPGREP_FALLBACK = 'ripgrep_fallback',
LOOP_DETECTED = 'loop_detected',
LOOP_DETECTION_DISABLED = 'loop_detection_disabled',
NEXT_SPEAKER_CHECK = 'next_speaker_check',
SLASH_COMMAND = 'slash_command',
MALFORMED_JSON_RESPONSE = 'malformed_json_response',
@@ -55,6 +67,12 @@ export enum EventNames {
INVALID_CHUNK = 'invalid_chunk',
CONTENT_RETRY = 'content_retry',
CONTENT_RETRY_FAILURE = 'content_retry_failure',
EXTENSION_ENABLE = 'extension_enable',
EXTENSION_DISABLE = 'extension_disable',
EXTENSION_INSTALL = 'extension_install',
EXTENSION_UNINSTALL = 'extension_uninstall',
TOOL_OUTPUT_TRUNCATED = 'tool_output_truncated',
MODEL_SLASH_COMMAND = 'model_slash_command',
}
export interface LogResponse {
@@ -98,10 +116,12 @@ export interface LogRequest {
function determineSurface(): string {
if (process.env['SURFACE']) {
return process.env['SURFACE'];
} else if (isCloudShell()) {
return IDE_DEFINITIONS.cloudshell.name;
} else if (process.env['GITHUB_SHA']) {
return 'GitHub';
} else if (process.env['TERM_PROGRAM'] === 'vscode') {
return detectIdeFromEnv() || DetectedIde.VSCode;
return detectIdeFromEnv().name || IDE_DEFINITIONS.vscode.name;
} else {
return 'SURFACE_NOT_SET';
}
@@ -461,14 +481,26 @@ export class ClearcutLogger {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_TYPE,
value: JSON.stringify(event.tool_type),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_CALL_CONTENT_LENGTH,
value: JSON.stringify(event.content_length),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_CALL_MCP_SERVER_NAME,
value: JSON.stringify(event.mcp_server_name),
},
];
if (event.metadata) {
const metadataMapping: { [key: string]: EventMetadataKey } = {
ai_added_lines: EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
ai_removed_lines: EventMetadataKey.GEMINI_CLI_AI_REMOVED_LINES,
model_added_lines: EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
model_removed_lines: EventMetadataKey.GEMINI_CLI_AI_REMOVED_LINES,
model_added_chars: EventMetadataKey.GEMINI_CLI_AI_ADDED_CHARS,
model_removed_chars: EventMetadataKey.GEMINI_CLI_AI_REMOVED_CHARS,
user_added_lines: EventMetadataKey.GEMINI_CLI_USER_ADDED_LINES,
user_removed_lines: EventMetadataKey.GEMINI_CLI_USER_REMOVED_LINES,
user_added_chars: EventMetadataKey.GEMINI_CLI_USER_ADDED_CHARS,
user_removed_chars: EventMetadataKey.GEMINI_CLI_USER_REMOVED_CHARS,
};
for (const [key, gemini_cli_key] of Object.entries(metadataMapping)) {
@@ -517,28 +549,6 @@ export class ClearcutLogger {
});
}
if (event.diff_stat) {
const metadataMapping: { [key: string]: EventMetadataKey } = {
ai_added_lines: EventMetadataKey.GEMINI_CLI_AI_ADDED_LINES,
ai_removed_lines: EventMetadataKey.GEMINI_CLI_AI_REMOVED_LINES,
user_added_lines: EventMetadataKey.GEMINI_CLI_USER_ADDED_LINES,
user_removed_lines: EventMetadataKey.GEMINI_CLI_USER_REMOVED_LINES,
};
for (const [key, gemini_cli_key] of Object.entries(metadataMapping)) {
if (
event.diff_stat[key as keyof typeof event.diff_stat] !== undefined
) {
data.push({
gemini_cli_key,
value: JSON.stringify(
event.diff_stat[key as keyof typeof event.diff_stat],
),
});
}
}
}
const logEvent = this.createLogEvent(EventNames.FILE_OPERATION, data);
this.enqueueLogEvent(logEvent);
this.flushIfNeeded();
@@ -570,10 +580,6 @@ export class ClearcutLogger {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_API_RESPONSE_DURATION_MS,
value: JSON.stringify(event.duration_ms),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_API_ERROR_MESSAGE,
value: JSON.stringify(event.error),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_API_RESPONSE_INPUT_TOKEN_COUNT,
@@ -653,6 +659,13 @@ export class ClearcutLogger {
});
}
logRipgrepFallbackEvent(): void {
this.enqueueLogEvent(this.createLogEvent(EventNames.RIPGREP_FALLBACK, []));
this.flushToClearcut().catch((error) => {
console.debug('Error flushing to Clearcut:', error);
});
}
logLoopDetectedEvent(event: LoopDetectedEvent): void {
const data: EventValue[] = [
{
@@ -665,6 +678,15 @@ export class ClearcutLogger {
this.flushIfNeeded();
}
logLoopDetectionDisabledEvent(): void {
const data: EventValue[] = [];
this.enqueueLogEvent(
this.createLogEvent(EventNames.LOOP_DETECTION_DISABLED, data),
);
this.flushIfNeeded();
}
logNextSpeakerCheck(event: NextSpeakerCheckEvent): void {
const data: EventValue[] = [
{
@@ -813,6 +835,10 @@ export class ClearcutLogger {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_CONTENT_RETRY_DELAY_MS,
value: String(event.retry_delay_ms),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_API_REQUEST_MODEL,
value: event.model,
},
];
this.enqueueLogEvent(this.createLogEvent(EventNames.CONTENT_RETRY, data));
@@ -831,6 +857,10 @@ export class ClearcutLogger {
EventMetadataKey.GEMINI_CLI_CONTENT_RETRY_FAILURE_FINAL_ERROR_TYPE,
value: event.final_error_type,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_API_REQUEST_MODEL,
value: event.model,
},
];
if (event.total_duration_ms) {
@@ -847,6 +877,143 @@ export class ClearcutLogger {
this.flushIfNeeded();
}
logExtensionInstallEvent(event: ExtensionInstallEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_NAME,
value: event.extension_name,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_VERSION,
value: event.extension_version,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_SOURCE,
value: event.extension_source,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_INSTALL_STATUS,
value: event.status,
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.EXTENSION_INSTALL, data),
);
this.flushToClearcut().catch((error) => {
console.debug('Error flushing to Clearcut:', error);
});
}
logExtensionUninstallEvent(event: ExtensionUninstallEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_NAME,
value: event.extension_name,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_UNINSTALL_STATUS,
value: event.status,
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.EXTENSION_UNINSTALL, data),
);
this.flushToClearcut().catch((error) => {
console.debug('Error flushing to Clearcut:', error);
});
}
logToolOutputTruncatedEvent(event: ToolOutputTruncatedEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_CALL_NAME,
value: JSON.stringify(event.tool_name),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_ORIGINAL_LENGTH,
value: JSON.stringify(event.original_content_length),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_TRUNCATED_LENGTH,
value: JSON.stringify(event.truncated_content_length),
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_THRESHOLD,
value: JSON.stringify(event.threshold),
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_LINES,
value: JSON.stringify(event.lines),
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.TOOL_OUTPUT_TRUNCATED, data),
);
this.flushIfNeeded();
}
logExtensionEnableEvent(event: ExtensionEnableEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_NAME,
value: event.extension_name,
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_EXTENSION_ENABLE_SETTING_SCOPE,
value: event.setting_scope,
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.EXTENSION_ENABLE, data),
);
this.flushToClearcut().catch((error) => {
console.debug('Error flushing to Clearcut:', error);
});
}
logModelSlashCommandEvent(event: ModelSlashCommandEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_MODEL_SLASH_COMMAND,
value: event.model_name,
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.MODEL_SLASH_COMMAND, data),
);
this.flushIfNeeded();
}
logExtensionDisableEvent(event: ExtensionDisableEvent): void {
const data: EventValue[] = [
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_EXTENSION_NAME,
value: event.extension_name,
},
{
gemini_cli_key:
EventMetadataKey.GEMINI_CLI_EXTENSION_DISABLE_SETTING_SCOPE,
value: event.setting_scope,
},
];
this.enqueueLogEvent(
this.createLogEvent(EventNames.EXTENSION_DISABLE, data),
);
this.flushToClearcut().catch((error) => {
console.debug('Error flushing to Clearcut:', error);
});
}
/**
* Adds default fields to data, and returns a new data array. This fields
* should exist on all log events.
@@ -889,6 +1056,18 @@ export class ClearcutLogger {
gemini_cli_key: EventMetadataKey.GEMINI_CLI_OS,
value: process.platform,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_NODE_VERSION,
value: process.versions.node,
},
{
gemini_cli_key: EventMetadataKey.GEMINI_CLI_USER_SETTINGS,
value: safeJsonStringify([
{
smart_edit_enabled: this.config?.getUseSmartEdit() ?? false,
},
]),
},
];
return [...data, ...defaultLogMetadata];
}

97
packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts
View File

@@ -6,6 +6,8 @@
// Defines valid event metadata keys for Qwen logging.
export enum EventMetadataKey {
// Deleted enums: 24
GEMINI_CLI_KEY_UNKNOWN = 0,
// ==========================================================================
@@ -48,6 +50,9 @@ export enum EventMetadataKey {
// Logs whether the session was configured to respect gitignore files.
GEMINI_CLI_START_SESSION_RESPECT_GITIGNORE = 12,
// Logs the output format of the session.
GEMINI_CLI_START_SESSION_OUTPUT_FORMAT = 94,
// ==========================================================================
// User Prompt Event Keys
// ===========================================================================
@@ -62,6 +67,9 @@ export enum EventMetadataKey {
// Logs the function name.
GEMINI_CLI_TOOL_CALL_NAME = 14,
// Logs the MCP server name.
GEMINI_CLI_TOOL_CALL_MCP_SERVER_NAME = 95,
// Logs the user's decision about how to handle the tool call.
GEMINI_CLI_TOOL_CALL_DECISION = 15,
@@ -77,6 +85,9 @@ export enum EventMetadataKey {
// Logs the tool call error type, if any.
GEMINI_CLI_TOOL_CALL_ERROR_TYPE = 19,
// Logs the length of tool output
GEMINI_CLI_TOOL_CALL_CONTENT_LENGTH = 93,
// ==========================================================================
// GenAI API Request Event Keys
// ===========================================================================
@@ -97,9 +108,6 @@ export enum EventMetadataKey {
// Logs the duration of the API call in milliseconds.
GEMINI_CLI_API_RESPONSE_DURATION_MS = 23,
// Logs the error message of the API call, if any.
GEMINI_CLI_API_ERROR_MESSAGE = 24,
// Logs the input token count of the API call.
GEMINI_CLI_API_RESPONSE_INPUT_TOKEN_COUNT = 25,
@@ -166,6 +174,9 @@ export enum EventMetadataKey {
// Logs the Gemini CLI OS
GEMINI_CLI_OS = 82,
// Logs active user settings
GEMINI_CLI_USER_SETTINGS = 84,
// ==========================================================================
// Loop Detected Event Keys
// ===========================================================================
@@ -222,6 +233,18 @@ export enum EventMetadataKey {
// Logs user removed lines in edit/write tool response.
GEMINI_CLI_USER_REMOVED_LINES = 50,
// Logs AI added characters in edit/write tool response.
GEMINI_CLI_AI_ADDED_CHARS = 103,
// Logs AI removed characters in edit/write tool response.
GEMINI_CLI_AI_REMOVED_CHARS = 104,
// Logs user added characters in edit/write tool response.
GEMINI_CLI_USER_ADDED_CHARS = 105,
// Logs user removed characters in edit/write tool response.
GEMINI_CLI_USER_REMOVED_CHARS = 106,
// ==========================================================================
// Kitty Sequence Overflow Event Keys
// ===========================================================================
@@ -325,4 +348,72 @@ export enum EventMetadataKey {
// Logs the total duration in milliseconds for a content retry failure.
GEMINI_CLI_CONTENT_RETRY_FAILURE_TOTAL_DURATION_MS = 81,
// Logs the current nodejs version
GEMINI_CLI_NODE_VERSION = 83,
// ==========================================================================
// Extension Install Event Keys
// ===========================================================================
// Logs the name of the extension.
GEMINI_CLI_EXTENSION_NAME = 85,
// Logs the version of the extension.
GEMINI_CLI_EXTENSION_VERSION = 86,
// Logs the source of the extension.
GEMINI_CLI_EXTENSION_SOURCE = 87,
// Logs the status of the extension install.
GEMINI_CLI_EXTENSION_INSTALL_STATUS = 88,
// Logs the status of the extension uninstall
GEMINI_CLI_EXTENSION_UNINSTALL_STATUS = 96,
// Logs the setting scope for an extension enablement.
GEMINI_CLI_EXTENSION_ENABLE_SETTING_SCOPE = 102,
// Logs the setting scope for an extension disablement.
GEMINI_CLI_EXTENSION_DISABLE_SETTING_SCOPE = 107,
// ==========================================================================
// Tool Output Truncated Event Keys
// ===========================================================================
// Logs the original length of the tool output.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_ORIGINAL_LENGTH = 89,
// Logs the truncated length of the tool output.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_TRUNCATED_LENGTH = 90,
// Logs the threshold at which the tool output was truncated.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_THRESHOLD = 91,
// Logs the number of lines the tool output was truncated to.
GEMINI_CLI_TOOL_OUTPUT_TRUNCATED_LINES = 92,
// ==========================================================================
// Model Router Event Keys
// ==========================================================================
// Logs the outcome of a model routing decision (e.g., which route/model was
// selected).
GEMINI_CLI_ROUTING_DECISION = 97,
// Logs an event when the model router fails to make a decision or the chosen
// route fails.
GEMINI_CLI_ROUTING_FAILURE = 98,
// Logs the latency in milliseconds for the router to make a decision.
GEMINI_CLI_ROUTING_LATENCY_MS = 99,
// Logs a specific reason for a routing failure.
GEMINI_CLI_ROUTING_FAILURE_REASON = 100,
// Logs the source of the decision.
GEMINI_CLI_ROUTING_DECISION_SOURCE = 101,
// Logs an event when the user uses the /model command.
GEMINI_CLI_MODEL_SLASH_COMMAND = 108,
}

155
packages/core/src/telemetry/config.test.ts Normal file
View File

@@ -0,0 +1,155 @@
/**
* @license
* Copyright 2025 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
import { describe, it, expect } from 'vitest';
import {
parseBooleanEnvFlag,
parseTelemetryTargetValue,
resolveTelemetrySettings,
} from './config.js';
import { TelemetryTarget } from './index.js';
describe('telemetry/config helpers', () => {
describe('parseBooleanEnvFlag', () => {
it('returns undefined for undefined', () => {
expect(parseBooleanEnvFlag(undefined)).toBeUndefined();
});
it('parses true values', () => {
expect(parseBooleanEnvFlag('true')).toBe(true);
expect(parseBooleanEnvFlag('1')).toBe(true);
});
it('parses false/other values as false', () => {
expect(parseBooleanEnvFlag('false')).toBe(false);
expect(parseBooleanEnvFlag('0')).toBe(false);
expect(parseBooleanEnvFlag('TRUE')).toBe(false);
expect(parseBooleanEnvFlag('random')).toBe(false);
expect(parseBooleanEnvFlag('')).toBe(false);
});
});
describe('parseTelemetryTargetValue', () => {
it('parses string values', () => {
expect(parseTelemetryTargetValue('local')).toBe(TelemetryTarget.LOCAL);
expect(parseTelemetryTargetValue('gcp')).toBe(TelemetryTarget.GCP);
});
it('accepts enum values', () => {
expect(parseTelemetryTargetValue(TelemetryTarget.LOCAL)).toBe(
TelemetryTarget.LOCAL,
);
expect(parseTelemetryTargetValue(TelemetryTarget.GCP)).toBe(
TelemetryTarget.GCP,
);
});
it('returns undefined for unknown', () => {
expect(parseTelemetryTargetValue('other')).toBeUndefined();
expect(parseTelemetryTargetValue(undefined)).toBeUndefined();
});
});
describe('resolveTelemetrySettings', () => {
it('falls back to settings when no argv/env provided', async () => {
const settings = {
enabled: false,
target: TelemetryTarget.LOCAL,
otlpEndpoint: 'http://localhost:4317',
otlpProtocol: 'grpc' as const,
logPrompts: false,
outfile: 'settings.log',
useCollector: false,
};
const resolved = await resolveTelemetrySettings({ settings });
expect(resolved).toEqual(settings);
});
it('uses env over settings and argv over env', async () => {
const settings = {
enabled: false,
target: TelemetryTarget.LOCAL,
otlpEndpoint: 'http://settings:4317',
otlpProtocol: 'grpc' as const,
logPrompts: false,
outfile: 'settings.log',
useCollector: false,
};
const env = {
GEMINI_TELEMETRY_ENABLED: '1',
GEMINI_TELEMETRY_TARGET: 'gcp',
GEMINI_TELEMETRY_OTLP_ENDPOINT: 'http://env:4317',
GEMINI_TELEMETRY_OTLP_PROTOCOL: 'http',
GEMINI_TELEMETRY_LOG_PROMPTS: 'true',
GEMINI_TELEMETRY_OUTFILE: 'env.log',
GEMINI_TELEMETRY_USE_COLLECTOR: 'true',
} as Record<string, string>;
const argv = {
telemetry: false,
telemetryTarget: 'local',
telemetryOtlpEndpoint: 'http://argv:4317',
telemetryOtlpProtocol: 'grpc',
telemetryLogPrompts: false,
telemetryOutfile: 'argv.log',
};
const resolvedEnv = await resolveTelemetrySettings({ env, settings });
expect(resolvedEnv).toEqual({
enabled: true,
target: TelemetryTarget.GCP,
otlpEndpoint: 'http://env:4317',
otlpProtocol: 'http',
logPrompts: true,
outfile: 'env.log',
useCollector: true,
});
const resolvedArgv = await resolveTelemetrySettings({
argv,
env,
settings,
});
expect(resolvedArgv).toEqual({
enabled: false,
target: TelemetryTarget.LOCAL,
otlpEndpoint: 'http://argv:4317',
otlpProtocol: 'grpc',
logPrompts: false,
outfile: 'argv.log',
useCollector: true, // from env as no argv option
});
});
it('falls back to OTEL_EXPORTER_OTLP_ENDPOINT when GEMINI var is missing', async () => {
const settings = {};
const env = {
OTEL_EXPORTER_OTLP_ENDPOINT: 'http://otel:4317',
} as Record<string, string>;
const resolved = await resolveTelemetrySettings({ env, settings });
expect(resolved.otlpEndpoint).toBe('http://otel:4317');
});
it('throws on unknown protocol values', async () => {
const env = { GEMINI_TELEMETRY_OTLP_PROTOCOL: 'unknown' } as Record<
string,
string
>;
await expect(resolveTelemetrySettings({ env })).rejects.toThrow(
/Invalid telemetry OTLP protocol/i,
);
});
it('throws on unknown target values', async () => {
const env = { GEMINI_TELEMETRY_TARGET: 'unknown' } as Record<
string,
string
>;
await expect(resolveTelemetrySettings({ env })).rejects.toThrow(
/Invalid telemetry target/i,
);
});
});
});

120
packages/core/src/telemetry/config.ts Normal file
View File

@@ -0,0 +1,120 @@
/**
* @license
* Copyright 2025 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
import type { TelemetrySettings } from '../config/config.js';
import { FatalConfigError } from '../utils/errors.js';
import { TelemetryTarget } from './index.js';
/**
* Parse a boolean environment flag. Accepts 'true'/'1' as true.
*/
export function parseBooleanEnvFlag(
value: string | undefined,
): boolean | undefined {
if (value === undefined) return undefined;
return value === 'true' || value === '1';
}
/**
* Normalize a telemetry target value into TelemetryTarget or undefined.
*/
export function parseTelemetryTargetValue(
value: string | TelemetryTarget | undefined,
): TelemetryTarget | undefined {
if (value === undefined) return undefined;
if (value === TelemetryTarget.LOCAL || value === 'local') {
return TelemetryTarget.LOCAL;
}
if (value === TelemetryTarget.GCP || value === 'gcp') {
return TelemetryTarget.GCP;
}
return undefined;
}
export interface TelemetryArgOverrides {
telemetry?: boolean;
telemetryTarget?: string | TelemetryTarget;
telemetryOtlpEndpoint?: string;
telemetryOtlpProtocol?: string;
telemetryLogPrompts?: boolean;
telemetryOutfile?: string;
}
/**
* Build TelemetrySettings by resolving from argv (highest), env, then settings.
*/
export async function resolveTelemetrySettings(options: {
argv?: TelemetryArgOverrides;
env?: Record<string, string | undefined>;
settings?: TelemetrySettings;
}): Promise<TelemetrySettings> {
const argv = options.argv ?? {};
const env = options.env ?? {};
const settings = options.settings ?? {};
const enabled =
argv.telemetry ??
parseBooleanEnvFlag(env['GEMINI_TELEMETRY_ENABLED']) ??
settings.enabled;
const rawTarget =
(argv.telemetryTarget as string | TelemetryTarget | undefined) ??
env['GEMINI_TELEMETRY_TARGET'] ??
(settings.target as string | TelemetryTarget | undefined);
const target = parseTelemetryTargetValue(rawTarget);
if (rawTarget !== undefined && target === undefined) {
throw new FatalConfigError(
`Invalid telemetry target: ${String(
rawTarget,
)}. Valid values are: local, gcp`,
);
}
const otlpEndpoint =
argv.telemetryOtlpEndpoint ??
env['GEMINI_TELEMETRY_OTLP_ENDPOINT'] ??
env['OTEL_EXPORTER_OTLP_ENDPOINT'] ??
settings.otlpEndpoint;
const rawProtocol =
(argv.telemetryOtlpProtocol as string | undefined) ??
env['GEMINI_TELEMETRY_OTLP_PROTOCOL'] ??
settings.otlpProtocol;
const otlpProtocol = (['grpc', 'http'] as const).find(
(p) => p === rawProtocol,
);
if (rawProtocol !== undefined && otlpProtocol === undefined) {
throw new FatalConfigError(
`Invalid telemetry OTLP protocol: ${String(
rawProtocol,
)}. Valid values are: grpc, http`,
);
}
const logPrompts =
argv.telemetryLogPrompts ??
parseBooleanEnvFlag(env['GEMINI_TELEMETRY_LOG_PROMPTS']) ??
settings.logPrompts;
const outfile =
argv.telemetryOutfile ??
env['GEMINI_TELEMETRY_OUTFILE'] ??
settings.outfile;
const useCollector =
parseBooleanEnvFlag(env['GEMINI_TELEMETRY_USE_COLLECTOR']) ??
settings.useCollector;
return {
enabled,
target,
otlpEndpoint,
otlpProtocol,
logPrompts,
outfile,
useCollector,
};
}

25
packages/core/src/telemetry/constants.ts
View File

@@ -13,7 +13,12 @@ export const EVENT_API_ERROR = 'qwen-code.api_error';
export const EVENT_API_CANCEL = 'qwen-code.api_cancel';
export const EVENT_API_RESPONSE = 'qwen-code.api_response';
export const EVENT_CLI_CONFIG = 'qwen-code.config';
export const EVENT_EXTENSION_DISABLE = 'qwen-code.extension_disable';
export const EVENT_EXTENSION_ENABLE = 'qwen-code.extension_enable';
export const EVENT_EXTENSION_INSTALL = 'qwen-code.extension_install';
export const EVENT_EXTENSION_UNINSTALL = 'qwen-code.extension_uninstall';
export const EVENT_FLASH_FALLBACK = 'qwen-code.flash_fallback';
export const EVENT_RIPGREP_FALLBACK = 'qwen-code.ripgrep_fallback';
export const EVENT_NEXT_SPEAKER_CHECK = 'qwen-code.next_speaker_check';
export const EVENT_SLASH_COMMAND = 'qwen-code.slash_command';
export const EVENT_IDE_CONNECTION = 'qwen-code.ide_connection';
@@ -25,18 +30,12 @@ export const EVENT_CONTENT_RETRY_FAILURE =
export const EVENT_CONVERSATION_FINISHED = 'qwen-code.conversation_finished';
export const EVENT_MALFORMED_JSON_RESPONSE =
'qwen-code.malformed_json_response';
export const EVENT_FILE_OPERATION = 'qwen-code.file_operation';
export const EVENT_MODEL_SLASH_COMMAND = 'qwen-code.slash_command.model';
export const EVENT_SUBAGENT_EXECUTION = 'qwen-code.subagent_execution';
export const METRIC_TOOL_CALL_COUNT = 'qwen-code.tool.call.count';
export const METRIC_TOOL_CALL_LATENCY = 'qwen-code.tool.call.latency';
export const METRIC_API_REQUEST_COUNT = 'qwen-code.api.request.count';
export const METRIC_API_REQUEST_LATENCY = 'qwen-code.api.request.latency';
export const METRIC_TOKEN_USAGE = 'qwen-code.token.usage';
export const METRIC_SESSION_COUNT = 'qwen-code.session.count';
export const METRIC_FILE_OPERATION_COUNT = 'qwen-code.file.operation.count';
export const METRIC_INVALID_CHUNK_COUNT = 'qwen-code.chat.invalid_chunk.count';
export const METRIC_CONTENT_RETRY_COUNT = 'qwen-code.chat.content_retry.count';
export const METRIC_CONTENT_RETRY_FAILURE_COUNT =
'qwen-code.chat.content_retry_failure.count';
export const METRIC_SUBAGENT_EXECUTION_COUNT =
'qwen-code.subagent.execution.count';
// Performance Events
export const EVENT_STARTUP_PERFORMANCE = 'qwen-code.startup.performance';
export const EVENT_MEMORY_USAGE = 'qwen-code.memory.usage';
export const EVENT_PERFORMANCE_BASELINE = 'qwen-code.performance.baseline';
export const EVENT_PERFORMANCE_REGRESSION = 'qwen-code.performance.regression';

107
packages/core/src/telemetry/index.ts
View File

@@ -13,48 +13,87 @@ export enum TelemetryTarget {
const DEFAULT_TELEMETRY_TARGET = TelemetryTarget.LOCAL;
const DEFAULT_OTLP_ENDPOINT = 'http://localhost:4317';
export { SpanStatusCode, ValueType } from '@opentelemetry/api';
export { SemanticAttributes } from '@opentelemetry/semantic-conventions';
export {
logApiError,
logApiCancel,
logApiRequest,
logApiResponse,
logChatCompression,
logCliConfiguration,
logConversationFinishedEvent,
logFlashFallback,
logKittySequenceOverflow,
logSlashCommand,
logToolCall,
logUserPrompt,
} from './loggers.js';
export { DEFAULT_TELEMETRY_TARGET, DEFAULT_OTLP_ENDPOINT };
export {
initializeTelemetry,
isTelemetrySdkInitialized,
shutdownTelemetry,
isTelemetrySdkInitialized,
} from './sdk.js';
export {
ApiErrorEvent,
ApiCancelEvent,
ApiRequestEvent,
ApiResponseEvent,
ConversationFinishedEvent,
EndSessionEvent,
FlashFallbackEvent,
KittySequenceOverflowEvent,
makeChatCompressionEvent,
makeSlashCommandEvent,
resolveTelemetrySettings,
parseBooleanEnvFlag,
parseTelemetryTargetValue,
} from './config.js';
export {
logCliConfiguration,
logUserPrompt,
logToolCall,
logApiRequest,
logApiError,
logApiCancel,
logApiResponse,
logFlashFallback,
logSlashCommand,
logConversationFinishedEvent,
logKittySequenceOverflow,
logChatCompression,
logToolOutputTruncated,
logExtensionEnable,
logExtensionInstallEvent,
logExtensionUninstall,
logRipgrepFallback,
logNextSpeakerCheck,
} from './loggers.js';
export type { SlashCommandEvent, ChatCompressionEvent } from './types.js';
export {
SlashCommandStatus,
EndSessionEvent,
UserPromptEvent,
ApiRequestEvent,
ApiErrorEvent,
ApiResponseEvent,
ApiCancelEvent,
FlashFallbackEvent,
StartSessionEvent,
ToolCallEvent,
UserPromptEvent,
} from './types.js';
export type {
ChatCompressionEvent,
SlashCommandEvent,
TelemetryEvent,
ConversationFinishedEvent,
KittySequenceOverflowEvent,
ToolOutputTruncatedEvent,
RipgrepFallbackEvent,
NextSpeakerCheckEvent,
} from './types.js';
export { makeSlashCommandEvent, makeChatCompressionEvent } from './types.js';
export type { TelemetryEvent } from './types.js';
export { SpanStatusCode, ValueType } from '@opentelemetry/api';
export { SemanticAttributes } from '@opentelemetry/semantic-conventions';
export * from './uiTelemetry.js';
export {
// Core metrics functions
recordToolCallMetrics,
recordTokenUsageMetrics,
recordApiResponseMetrics,
recordApiErrorMetrics,
recordFileOperationMetric,
recordInvalidChunk,
recordContentRetry,
recordContentRetryFailure,
// Performance monitoring functions
recordStartupPerformance,
recordMemoryUsage,
recordCpuUsage,
recordToolQueueDepth,
recordToolExecutionBreakdown,
recordTokenEfficiency,
recordApiRequestBreakdown,
recordPerformanceScore,
recordPerformanceRegression,
recordBaselineComparison,
isPerformanceMonitoringActive,
// Performance monitoring types
PerformanceMetricType,
MemoryMetricType,
ToolExecutionPhase,
ApiRequestPhase,
FileOperation,
} from './metrics.js';
export { QwenLogger } from './qwen-logger/qwen-logger.js';
export { DEFAULT_OTLP_ENDPOINT, DEFAULT_TELEMETRY_TARGET };

6
packages/core/src/telemetry/loggers.test.circular.ts
View File

@@ -17,7 +17,7 @@ import type {
ToolCallRequestInfo,
ToolCallResponseInfo,
} from '../core/turn.js';
import { MockTool } from '../test-utils/tools.js';
import { MockTool } from '../test-utils/mock-tool.js';
describe('Circular Reference Handling', () => {
it('should handle circular references in tool function arguments', () => {
@@ -59,7 +59,7 @@ describe('Circular Reference Handling', () => {
errorType: undefined,
};
const tool = new MockTool('mock-tool');
const tool = new MockTool({ name: 'mock-tool' });
const mockCompletedToolCall: CompletedToolCall = {
status: 'success',
request: mockRequest,
@@ -109,7 +109,7 @@ describe('Circular Reference Handling', () => {
errorType: undefined,
};
const tool = new MockTool('mock-tool');
const tool = new MockTool({ name: 'mock-tool' });
const mockCompletedToolCall: CompletedToolCall = {
status: 'success',
request: mockRequest,

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

@@ -4,10 +4,9 @@
* SPDX-License-Identifier: Apache-2.0
*/
import type { GenerateContentResponseUsageMetadata } from '@google/genai';
import { logs } from '@opentelemetry/api-logs';
import { SemanticAttributes } from '@opentelemetry/semantic-conventions';
import { beforeEach, describe, expect, it, vi } from 'vitest';
import { beforeEach, afterEach, describe, expect, it, vi } from 'vitest';
import type { Config } from '../config/config.js';
import type {
AnyToolInvocation,
@@ -23,8 +22,7 @@ import {
ToolErrorType,
ToolRegistry,
} from '../index.js';
import { makeFakeConfig } from '../test-utils/config.js';
import { UserAccountManager } from '../utils/userAccountManager.js';
import { OutputFormat } from '../output/types.js';
import {
EVENT_API_REQUEST,
EVENT_API_RESPONSE,
@@ -32,15 +30,30 @@ import {
EVENT_FLASH_FALLBACK,
EVENT_TOOL_CALL,
EVENT_USER_PROMPT,
EVENT_MALFORMED_JSON_RESPONSE,
EVENT_FILE_OPERATION,
EVENT_RIPGREP_FALLBACK,
EVENT_EXTENSION_ENABLE,
EVENT_EXTENSION_DISABLE,
EVENT_EXTENSION_INSTALL,
EVENT_EXTENSION_UNINSTALL,
} from './constants.js';
import {
logApiRequest,
logApiResponse,
logChatCompression,
logCliConfiguration,
logFlashFallback,
logToolCall,
logUserPrompt,
logToolCall,
logFlashFallback,
logChatCompression,
logMalformedJsonResponse,
logFileOperation,
logRipgrepFallback,
logToolOutputTruncated,
logExtensionEnable,
logExtensionDisable,
logExtensionInstallEvent,
logExtensionUninstall,
} from './loggers.js';
import * as metrics from './metrics.js';
import { QwenLogger } from './qwen-logger/qwen-logger.js';
@@ -53,9 +66,25 @@ import {
StartSessionEvent,
ToolCallEvent,
UserPromptEvent,
RipgrepFallbackEvent,
MalformedJsonResponseEvent,
makeChatCompressionEvent,
FileOperationEvent,
ToolOutputTruncatedEvent,
ExtensionEnableEvent,
ExtensionDisableEvent,
ExtensionInstallEvent,
ExtensionUninstallEvent,
} from './types.js';
import { FileOperation } from './metrics.js';
import type {
CallableTool,
GenerateContentResponseUsageMetadata,
} from '@google/genai';
import { DiscoveredMCPTool } from '../tools/mcp-tool.js';
import * as uiTelemetry from './uiTelemetry.js';
import { UserAccountManager } from '../utils/userAccountManager.js';
import { makeFakeConfig } from '../test-utils/config.js';
describe('loggers', () => {
const mockLogger = {
@@ -147,6 +176,7 @@ describe('loggers', () => {
getQuestion: () => 'test-question',
getTargetDir: () => 'target-dir',
getProxy: () => 'http://test.proxy.com:8080',
getOutputFormat: () => OutputFormat.JSON,
} as unknown as Config;
const startSessionEvent = new StartSessionEvent(mockConfig);
@@ -173,6 +203,7 @@ describe('loggers', () => {
mcp_servers_count: 1,
mcp_tools: undefined,
mcp_tools_count: undefined,
output_format: 'json',
},
});
});
@@ -307,23 +338,19 @@ describe('loggers', () => {
response_text: 'test-response',
prompt_id: 'prompt-id-1',
auth_type: 'oauth-personal',
error: undefined,
},
});
expect(mockMetrics.recordApiResponseMetrics).toHaveBeenCalledWith(
mockConfig,
'test-model',
100,
200,
undefined,
{ model: 'test-model', status_code: 200 },
);
expect(mockMetrics.recordTokenUsageMetrics).toHaveBeenCalledWith(
mockConfig,
'test-model',
50,
'output',
{ model: 'test-model', type: 'output' },
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -332,46 +359,6 @@ describe('loggers', () => {
'event.timestamp': '2025-01-01T00:00:00.000Z',
});
});
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-response-id-2',
'test-model',
100,
'prompt-id-1',
AuthType.USE_GEMINI,
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',
'user.email': 'test-user@example.com',
...event,
'event.name': EVENT_API_RESPONSE,
'event.timestamp': '2025-01-01T00:00:00.000Z',
'error.message': 'test-error',
},
});
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
...event,
'event.name': EVENT_API_RESPONSE,
'event.timestamp': '2025-01-01T00:00:00.000Z',
});
});
});
describe('logApiRequest', () => {
@@ -449,6 +436,55 @@ describe('loggers', () => {
});
});
describe('logRipgrepFallback', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logRipgrepFallbackEvent');
});
it('should log ripgrep fallback event', () => {
const event = new RipgrepFallbackEvent();
logRipgrepFallback(mockConfig, event);
expect(QwenLogger.prototype.logRipgrepFallbackEvent).toHaveBeenCalled();
const emittedEvent = mockLogger.emit.mock.calls[0][0];
expect(emittedEvent.body).toBe('Switching to grep as fallback.');
expect(emittedEvent.attributes).toEqual(
expect.objectContaining({
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_RIPGREP_FALLBACK,
error: undefined,
}),
);
});
it('should log ripgrep fallback event with an error', () => {
const event = new RipgrepFallbackEvent('rg not found');
logRipgrepFallback(mockConfig, event);
expect(QwenLogger.prototype.logRipgrepFallbackEvent).toHaveBeenCalled();
const emittedEvent = mockLogger.emit.mock.calls[0][0];
expect(emittedEvent.body).toBe('Switching to grep as fallback.');
expect(emittedEvent.attributes).toEqual(
expect.objectContaining({
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_RIPGREP_FALLBACK,
error: 'rg not found',
}),
);
});
});
describe('logToolCall', () => {
const cfg1 = {
getSessionId: () => 'test-session-id',
@@ -520,9 +556,25 @@ describe('loggers', () => {
response: {
callId: 'test-call-id',
responseParts: [{ text: 'test-response' }],
resultDisplay: undefined,
resultDisplay: {
fileDiff: 'diff',
fileName: 'file.txt',
originalContent: 'old content',
newContent: 'new content',
diffStat: {
model_added_lines: 1,
model_removed_lines: 2,
model_added_chars: 3,
model_removed_chars: 4,
user_added_lines: 5,
user_removed_lines: 6,
user_added_chars: 7,
user_removed_chars: 8,
},
},
error: undefined,
errorType: undefined,
contentLength: 13,
},
tool,
invocation: {} as AnyToolInvocation,
@@ -557,17 +609,30 @@ describe('loggers', () => {
tool_type: 'native',
error: undefined,
error_type: undefined,
metadata: undefined,
metadata: {
model_added_lines: 1,
model_removed_lines: 2,
model_added_chars: 3,
model_removed_chars: 4,
user_added_lines: 5,
user_removed_lines: 6,
user_added_chars: 7,
user_removed_chars: 8,
},
content_length: 13,
},
});
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
mockConfig,
'test-function',
100,
true,
ToolCallDecision.ACCEPT,
'native',
{
function_name: 'test-function',
success: true,
decision: ToolCallDecision.ACCEPT,
tool_type: 'native',
},
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -595,6 +660,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: undefined,
},
durationMs: 100,
outcome: ToolConfirmationOutcome.Cancel,
@@ -628,16 +694,19 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: undefined,
},
});
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
mockConfig,
'test-function',
100,
false,
ToolCallDecision.REJECT,
'native',
{
function_name: 'test-function',
success: false,
decision: ToolCallDecision.REJECT,
tool_type: 'native',
},
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -666,6 +735,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: 13,
},
outcome: ToolConfirmationOutcome.ModifyWithEditor,
tool: new EditTool(mockConfig),
@@ -701,16 +771,19 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: 13,
},
});
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
mockConfig,
'test-function',
100,
true,
ToolCallDecision.MODIFY,
'native',
{
function_name: 'test-function',
success: true,
decision: ToolCallDecision.MODIFY,
tool_type: 'native',
},
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -739,6 +812,7 @@ describe('loggers', () => {
resultDisplay: undefined,
error: undefined,
errorType: undefined,
contentLength: 13,
},
tool: new EditTool(mockConfig),
invocation: {} as AnyToolInvocation,
@@ -773,16 +847,19 @@ describe('loggers', () => {
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: 13,
},
});
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
mockConfig,
'test-function',
100,
true,
undefined,
'native',
{
function_name: 'test-function',
success: true,
decision: undefined,
tool_type: 'native',
},
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -793,6 +870,7 @@ describe('loggers', () => {
});
it('should log a failed tool call with an error', () => {
const errorMessage = 'test-error';
const call: ErroredToolCall = {
status: 'error',
request: {
@@ -809,11 +887,9 @@ describe('loggers', () => {
callId: 'test-call-id',
responseParts: [{ text: 'test-response' }],
resultDisplay: undefined,
error: {
name: 'test-error-type',
message: 'test-error',
},
error: new Error(errorMessage),
errorType: ToolErrorType.UNKNOWN,
contentLength: errorMessage.length,
},
durationMs: 100,
};
@@ -848,16 +924,19 @@ describe('loggers', () => {
tool_type: 'native',
decision: undefined,
metadata: undefined,
content_length: errorMessage.length,
},
});
expect(mockMetrics.recordToolCallMetrics).toHaveBeenCalledWith(
mockConfig,
'test-function',
100,
false,
undefined,
'native',
{
function_name: 'test-function',
success: false,
decision: undefined,
tool_type: 'native',
},
);
expect(mockUiEvent.addEvent).toHaveBeenCalledWith({
@@ -866,5 +945,356 @@ describe('loggers', () => {
'event.timestamp': '2025-01-01T00:00:00.000Z',
});
});
it('should log a tool call with mcp_server_name for MCP tools', () => {
const mockMcpTool = new DiscoveredMCPTool(
{} as CallableTool,
'mock_mcp_server',
'mock_mcp_tool',
'tool description',
{
type: 'object',
properties: {
arg1: { type: 'string' },
arg2: { type: 'number' },
},
required: ['arg1', 'arg2'],
},
);
const call: CompletedToolCall = {
status: 'success',
request: {
name: 'mock_mcp_tool',
args: { arg1: 'value1', arg2: 2 },
callId: 'test-call-id',
isClientInitiated: true,
prompt_id: 'prompt-id',
},
response: {
callId: 'test-call-id',
responseParts: [{ text: 'test-response' }],
resultDisplay: undefined,
error: undefined,
errorType: undefined,
},
tool: mockMcpTool,
invocation: {} as AnyToolInvocation,
durationMs: 100,
};
const event = new ToolCallEvent(call);
logToolCall(mockConfig, event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Tool call: mock_mcp_tool. Success: true. Duration: 100ms.',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_TOOL_CALL,
'event.timestamp': '2025-01-01T00:00:00.000Z',
function_name: 'mock_mcp_tool',
function_args: JSON.stringify(
{
arg1: 'value1',
arg2: 2,
},
null,
2,
),
duration_ms: 100,
status: 'success',
success: true,
prompt_id: 'prompt-id',
tool_type: 'mcp',
mcp_server_name: 'mock_mcp_server',
decision: undefined,
error: undefined,
error_type: undefined,
metadata: undefined,
content_length: undefined,
response_id: undefined,
},
});
});
});
describe('logMalformedJsonResponse', () => {
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logMalformedJsonResponseEvent');
});
it('logs the event to Clearcut and OTEL', () => {
const mockConfig = makeFakeConfig();
const event = new MalformedJsonResponseEvent('test-model');
logMalformedJsonResponse(mockConfig, event);
expect(
QwenLogger.prototype.logMalformedJsonResponseEvent,
).toHaveBeenCalledWith(event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Malformed JSON response from test-model.',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_MALFORMED_JSON_RESPONSE,
'event.timestamp': '2025-01-01T00:00:00.000Z',
model: 'test-model',
},
});
});
});
describe('logFileOperation', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getTargetDir: () => 'target-dir',
getUsageStatisticsEnabled: () => true,
getTelemetryEnabled: () => true,
getTelemetryLogPromptsEnabled: () => true,
} as Config;
const mockMetrics = {
recordFileOperationMetric: vi.fn(),
};
beforeEach(() => {
vi.spyOn(metrics, 'recordFileOperationMetric').mockImplementation(
mockMetrics.recordFileOperationMetric,
);
});
it('should log a file operation event', () => {
const event = new FileOperationEvent(
'test-tool',
FileOperation.READ,
10,
'text/plain',
'.txt',
'typescript',
);
logFileOperation(mockConfig, event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'File operation: read. Lines: 10.',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_FILE_OPERATION,
'event.timestamp': '2025-01-01T00:00:00.000Z',
tool_name: 'test-tool',
operation: 'read',
lines: 10,
mimetype: 'text/plain',
extension: '.txt',
programming_language: 'typescript',
},
});
expect(mockMetrics.recordFileOperationMetric).toHaveBeenCalledWith(
mockConfig,
{
operation: 'read',
lines: 10,
mimetype: 'text/plain',
extension: '.txt',
programming_language: 'typescript',
},
);
});
});
describe('logToolOutputTruncated', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
it('should log a tool output truncated event', () => {
const event = new ToolOutputTruncatedEvent('prompt-id-1', {
toolName: 'test-tool',
originalContentLength: 1000,
truncatedContentLength: 100,
threshold: 500,
lines: 10,
});
logToolOutputTruncated(mockConfig, event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Tool output truncated for test-tool.',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': 'tool_output_truncated',
'event.timestamp': '2025-01-01T00:00:00.000Z',
eventName: 'tool_output_truncated',
prompt_id: 'prompt-id-1',
tool_name: 'test-tool',
original_content_length: 1000,
truncated_content_length: 100,
threshold: 500,
lines: 10,
},
});
});
});
describe('logExtensionInstall', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logExtensionInstallEvent');
});
afterEach(() => {
vi.resetAllMocks();
});
it('should log extension install event', () => {
const event = new ExtensionInstallEvent(
'vscode',
'0.1.0',
'git',
'success',
);
logExtensionInstallEvent(mockConfig, event);
expect(
QwenLogger.prototype.logExtensionInstallEvent,
).toHaveBeenCalledWith(event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Installed extension vscode',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_EXTENSION_INSTALL,
'event.timestamp': '2025-01-01T00:00:00.000Z',
extension_name: 'vscode',
extension_version: '0.1.0',
extension_source: 'git',
status: 'success',
},
});
});
});
describe('logExtensionUninstall', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logExtensionUninstallEvent');
});
afterEach(() => {
vi.resetAllMocks();
});
it('should log extension uninstall event', () => {
const event = new ExtensionUninstallEvent('vscode', 'success');
logExtensionUninstall(mockConfig, event);
expect(
QwenLogger.prototype.logExtensionUninstallEvent,
).toHaveBeenCalledWith(event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Uninstalled extension vscode',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_EXTENSION_UNINSTALL,
'event.timestamp': '2025-01-01T00:00:00.000Z',
extension_name: 'vscode',
status: 'success',
},
});
});
});
describe('logExtensionEnable', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logExtensionEnableEvent');
});
afterEach(() => {
vi.resetAllMocks();
});
it('should log extension enable event', () => {
const event = new ExtensionEnableEvent('vscode', 'user');
logExtensionEnable(mockConfig, event);
expect(QwenLogger.prototype.logExtensionEnableEvent).toHaveBeenCalledWith(
event,
);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Enabled extension vscode',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_EXTENSION_ENABLE,
'event.timestamp': '2025-01-01T00:00:00.000Z',
extension_name: 'vscode',
setting_scope: 'user',
},
});
});
});
describe('logExtensionDisable', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getUsageStatisticsEnabled: () => true,
} as unknown as Config;
beforeEach(() => {
vi.spyOn(QwenLogger.prototype, 'logExtensionDisableEvent');
});
afterEach(() => {
vi.resetAllMocks();
});
it('should log extension disable event', () => {
const event = new ExtensionDisableEvent('vscode', 'user');
logExtensionDisable(mockConfig, event);
expect(
QwenLogger.prototype.logExtensionDisableEvent,
).toHaveBeenCalledWith(event);
expect(mockLogger.emit).toHaveBeenCalledWith({
body: 'Disabled extension vscode',
attributes: {
'session.id': 'test-session-id',
'user.email': 'test-user@example.com',
'event.name': EVENT_EXTENSION_DISABLE,
'event.timestamp': '2025-01-01T00:00:00.000Z',
extension_name: 'vscode',
setting_scope: 'user',
},
});
});
});
});

381
packages/core/src/telemetry/loggers.ts
View File

@@ -15,20 +15,28 @@ import {
EVENT_API_CANCEL,
EVENT_API_REQUEST,
EVENT_API_RESPONSE,
EVENT_CHAT_COMPRESSION,
EVENT_CLI_CONFIG,
EVENT_CONTENT_RETRY,
EVENT_CONTENT_RETRY_FAILURE,
EVENT_CONVERSATION_FINISHED,
EVENT_FLASH_FALLBACK,
EVENT_EXTENSION_UNINSTALL,
EVENT_EXTENSION_ENABLE,
EVENT_IDE_CONNECTION,
EVENT_INVALID_CHUNK,
EVENT_NEXT_SPEAKER_CHECK,
EVENT_SLASH_COMMAND,
EVENT_SUBAGENT_EXECUTION,
EVENT_TOOL_CALL,
EVENT_USER_PROMPT,
EVENT_FLASH_FALLBACK,
EVENT_NEXT_SPEAKER_CHECK,
SERVICE_NAME,
EVENT_SLASH_COMMAND,
EVENT_CONVERSATION_FINISHED,
EVENT_CHAT_COMPRESSION,
EVENT_CONTENT_RETRY,
EVENT_CONTENT_RETRY_FAILURE,
EVENT_FILE_OPERATION,
EVENT_RIPGREP_FALLBACK,
EVENT_EXTENSION_INSTALL,
EVENT_MODEL_SLASH_COMMAND,
EVENT_EXTENSION_DISABLE,
EVENT_SUBAGENT_EXECUTION,
EVENT_MALFORMED_JSON_RESPONSE,
EVENT_INVALID_CHUNK,
} from './constants.js';
import {
recordApiErrorMetrics,
@@ -38,6 +46,7 @@ import {
recordContentRetryFailure,
recordFileOperationMetric,
recordInvalidChunk,
recordModelSlashCommand,
recordSubagentExecutionMetrics,
recordTokenUsageMetrics,
recordToolCallMetrics,
@@ -49,24 +58,34 @@ import type {
ApiCancelEvent,
ApiRequestEvent,
ApiResponseEvent,
FileOperationEvent,
IdeConnectionEvent,
StartSessionEvent,
ToolCallEvent,
UserPromptEvent,
FlashFallbackEvent,
NextSpeakerCheckEvent,
LoopDetectedEvent,
LoopDetectionDisabledEvent,
SlashCommandEvent,
ConversationFinishedEvent,
KittySequenceOverflowEvent,
ChatCompressionEvent,
ContentRetryEvent,
ContentRetryFailureEvent,
ConversationFinishedEvent,
FileOperationEvent,
FlashFallbackEvent,
IdeConnectionEvent,
InvalidChunkEvent,
KittySequenceOverflowEvent,
LoopDetectedEvent,
NextSpeakerCheckEvent,
SlashCommandEvent,
StartSessionEvent,
RipgrepFallbackEvent,
ToolOutputTruncatedEvent,
ExtensionDisableEvent,
ExtensionEnableEvent,
ExtensionUninstallEvent,
ExtensionInstallEvent,
ModelSlashCommandEvent,
SubagentExecutionEvent,
ToolCallEvent,
UserPromptEvent,
MalformedJsonResponseEvent,
InvalidChunkEvent,
} from './types.js';
import { type UiEvent, uiTelemetryService } from './uiTelemetry.js';
import type { UiEvent } from './uiTelemetry.js';
import { uiTelemetryService } from './uiTelemetry.js';
const shouldLogUserPrompts = (config: Config): boolean =>
config.getTelemetryLogPromptsEnabled();
@@ -105,6 +124,7 @@ export function logCliConfiguration(
mcp_servers_count: event.mcp_servers_count,
mcp_tools: event.mcp_tools,
mcp_tools_count: event.mcp_tools_count,
output_format: event.output_format,
};
const logger = logs.getLogger(SERVICE_NAME);
@@ -173,14 +193,34 @@ export function logToolCall(config: Config, event: ToolCallEvent): void {
attributes,
};
logger.emit(logRecord);
recordToolCallMetrics(
config,
event.function_name,
event.duration_ms,
event.success,
event.decision,
event.tool_type,
);
recordToolCallMetrics(config, event.duration_ms, {
function_name: event.function_name,
success: event.success,
decision: event.decision,
tool_type: event.tool_type,
});
}
export function logToolOutputTruncated(
config: Config,
event: ToolOutputTruncatedEvent,
): void {
QwenLogger.getInstance(config)?.logToolOutputTruncatedEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': 'tool_output_truncated',
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Tool output truncated for ${event.tool_name}.`,
attributes,
};
logger.emit(logRecord);
}
export function logFileOperation(
@@ -190,15 +230,41 @@ export function logFileOperation(
QwenLogger.getInstance(config)?.logFileOperationEvent(event);
if (!isTelemetrySdkInitialized()) return;
recordFileOperationMetric(
config,
event.operation,
event.lines,
event.mimetype,
event.extension,
event.diff_stat,
event.programming_language,
);
const attributes: LogAttributes = {
...getCommonAttributes(config),
'event.name': EVENT_FILE_OPERATION,
'event.timestamp': new Date().toISOString(),
tool_name: event.tool_name,
operation: event.operation,
};
if (event.lines) {
attributes['lines'] = event.lines;
}
if (event.mimetype) {
attributes['mimetype'] = event.mimetype;
}
if (event.extension) {
attributes['extension'] = event.extension;
}
if (event.programming_language) {
attributes['programming_language'] = event.programming_language;
}
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `File operation: ${event.operation}. Lines: ${event.lines}.`,
attributes,
};
logger.emit(logRecord);
recordFileOperationMetric(config, {
operation: event.operation,
lines: event.lines,
mimetype: event.mimetype,
extension: event.extension,
programming_language: event.programming_language,
});
}
export function logApiRequest(config: Config, event: ApiRequestEvent): void {
@@ -242,6 +308,28 @@ export function logFlashFallback(
logger.emit(logRecord);
}
export function logRipgrepFallback(
config: Config,
event: RipgrepFallbackEvent,
): void {
QwenLogger.getInstance(config)?.logRipgrepFallbackEvent();
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_RIPGREP_FALLBACK,
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Switching to grep as fallback.`,
attributes,
};
logger.emit(logRecord);
}
export function logApiError(config: Config, event: ApiErrorEvent): void {
const uiEvent = {
...event,
@@ -275,13 +363,11 @@ export function logApiError(config: Config, event: ApiErrorEvent): void {
attributes,
};
logger.emit(logRecord);
recordApiErrorMetrics(
config,
event.model,
event.duration_ms,
event.status_code,
event.error_type,
);
recordApiErrorMetrics(config, event.duration_ms, {
model: event.model,
status_code: event.status_code,
error_type: event.error_type,
});
}
export function logApiCancel(config: Config, event: ApiCancelEvent): void {
@@ -328,9 +414,7 @@ export function logApiResponse(config: Config, event: ApiResponseEvent): void {
if (event.response_text) {
attributes['response_text'] = event.response_text;
}
if (event.error) {
attributes['error.message'] = event.error;
} else if (event.status_code) {
if (event.status_code) {
if (typeof event.status_code === 'number') {
attributes[SemanticAttributes.HTTP_STATUS_CODE] = event.status_code;
}
@@ -342,38 +426,30 @@ export function logApiResponse(config: Config, event: ApiResponseEvent): void {
attributes,
};
logger.emit(logRecord);
recordApiResponseMetrics(
config,
event.model,
event.duration_ms,
event.status_code,
event.error,
);
recordTokenUsageMetrics(
config,
event.model,
event.input_token_count,
'input',
);
recordTokenUsageMetrics(
config,
event.model,
event.output_token_count,
'output',
);
recordTokenUsageMetrics(
config,
event.model,
event.cached_content_token_count,
'cache',
);
recordTokenUsageMetrics(
config,
event.model,
event.thoughts_token_count,
'thought',
);
recordTokenUsageMetrics(config, event.model, event.tool_token_count, 'tool');
recordApiResponseMetrics(config, event.duration_ms, {
model: event.model,
status_code: event.status_code,
});
recordTokenUsageMetrics(config, event.input_token_count, {
model: event.model,
type: 'input',
});
recordTokenUsageMetrics(config, event.output_token_count, {
model: event.model,
type: 'output',
});
recordTokenUsageMetrics(config, event.cached_content_token_count, {
model: event.model,
type: 'cache',
});
recordTokenUsageMetrics(config, event.thoughts_token_count, {
model: event.model,
type: 'thought',
});
recordTokenUsageMetrics(config, event.tool_token_count, {
model: event.model,
type: 'tool',
});
}
export function logLoopDetected(
@@ -396,6 +472,13 @@ export function logLoopDetected(
logger.emit(logRecord);
}
export function logLoopDetectionDisabled(
config: Config,
_event: LoopDetectionDisabledEvent,
): void {
QwenLogger.getInstance(config)?.logLoopDetectionDisabledEvent();
}
export function logNextSpeakerCheck(
config: Config,
event: NextSpeakerCheckEvent,
@@ -522,6 +605,28 @@ export function logKittySequenceOverflow(
};
logger.emit(logRecord);
}
export function logMalformedJsonResponse(
config: Config,
event: MalformedJsonResponseEvent,
): void {
QwenLogger.getInstance(config)?.logMalformedJsonResponseEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_MALFORMED_JSON_RESPONSE,
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Malformed JSON response from ${event.model}.`,
attributes,
};
logger.emit(logRecord);
}
export function logInvalidChunk(
config: Config,
event: InvalidChunkEvent,
@@ -619,3 +724,117 @@ export function logSubagentExecution(
event.terminate_reason,
);
}
export function logModelSlashCommand(
config: Config,
event: ModelSlashCommandEvent,
): void {
QwenLogger.getInstance(config)?.logModelSlashCommandEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_MODEL_SLASH_COMMAND,
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Model slash command. Model: ${event.model_name}`,
attributes,
};
logger.emit(logRecord);
recordModelSlashCommand(config, event);
}
export function logExtensionInstallEvent(
config: Config,
event: ExtensionInstallEvent,
): void {
QwenLogger.getInstance(config)?.logExtensionInstallEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_EXTENSION_INSTALL,
'event.timestamp': new Date().toISOString(),
extension_name: event.extension_name,
extension_version: event.extension_version,
extension_source: event.extension_source,
status: event.status,
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Installed extension ${event.extension_name}`,
attributes,
};
logger.emit(logRecord);
}
export function logExtensionUninstall(
config: Config,
event: ExtensionUninstallEvent,
): void {
QwenLogger.getInstance(config)?.logExtensionUninstallEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_EXTENSION_UNINSTALL,
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Uninstalled extension ${event.extension_name}`,
attributes,
};
logger.emit(logRecord);
}
export function logExtensionEnable(
config: Config,
event: ExtensionEnableEvent,
): void {
QwenLogger.getInstance(config)?.logExtensionEnableEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_EXTENSION_ENABLE,
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Enabled extension ${event.extension_name}`,
attributes,
};
logger.emit(logRecord);
}
export function logExtensionDisable(
config: Config,
event: ExtensionDisableEvent,
): void {
QwenLogger.getInstance(config)?.logExtensionDisableEvent(event);
if (!isTelemetrySdkInitialized()) return;
const attributes: LogAttributes = {
...getCommonAttributes(config),
...event,
'event.name': EVENT_EXTENSION_DISABLE,
'event.timestamp': new Date().toISOString(),
};
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: `Disabled extension ${event.extension_name}`,
attributes,
};
logger.emit(logRecord);
}

712
packages/core/src/telemetry/metrics.test.ts
View File

@@ -13,7 +13,12 @@ import type {
Histogram,
} from '@opentelemetry/api';
import type { Config } from '../config/config.js';
import { FileOperation } from './metrics.js';
import {
FileOperation,
MemoryMetricType,
ToolExecutionPhase,
ApiRequestPhase,
} from './metrics.js';
import { makeFakeConfig } from '../test-utils/config.js';
const mockCounterAddFn: Mock<
@@ -49,11 +54,13 @@ function originalOtelMockFactory() {
},
ValueType: {
INT: 1,
DOUBLE: 2,
},
diag: {
setLogger: vi.fn(),
warn: vi.fn(),
},
};
} as const;
}
vi.mock('@opentelemetry/api');
@@ -63,6 +70,16 @@ describe('Telemetry Metrics', () => {
let recordTokenUsageMetricsModule: typeof import('./metrics.js').recordTokenUsageMetrics;
let recordFileOperationMetricModule: typeof import('./metrics.js').recordFileOperationMetric;
let recordChatCompressionMetricsModule: typeof import('./metrics.js').recordChatCompressionMetrics;
let recordStartupPerformanceModule: typeof import('./metrics.js').recordStartupPerformance;
let recordMemoryUsageModule: typeof import('./metrics.js').recordMemoryUsage;
let recordCpuUsageModule: typeof import('./metrics.js').recordCpuUsage;
let recordToolQueueDepthModule: typeof import('./metrics.js').recordToolQueueDepth;
let recordToolExecutionBreakdownModule: typeof import('./metrics.js').recordToolExecutionBreakdown;
let recordTokenEfficiencyModule: typeof import('./metrics.js').recordTokenEfficiency;
let recordApiRequestBreakdownModule: typeof import('./metrics.js').recordApiRequestBreakdown;
let recordPerformanceScoreModule: typeof import('./metrics.js').recordPerformanceScore;
let recordPerformanceRegressionModule: typeof import('./metrics.js').recordPerformanceRegression;
let recordBaselineComparisonModule: typeof import('./metrics.js').recordBaselineComparison;
beforeEach(async () => {
vi.resetModules();
@@ -78,6 +95,18 @@ describe('Telemetry Metrics', () => {
recordFileOperationMetricModule = metricsJsModule.recordFileOperationMetric;
recordChatCompressionMetricsModule =
metricsJsModule.recordChatCompressionMetrics;
recordStartupPerformanceModule = metricsJsModule.recordStartupPerformance;
recordMemoryUsageModule = metricsJsModule.recordMemoryUsage;
recordCpuUsageModule = metricsJsModule.recordCpuUsage;
recordToolQueueDepthModule = metricsJsModule.recordToolQueueDepth;
recordToolExecutionBreakdownModule =
metricsJsModule.recordToolExecutionBreakdown;
recordTokenEfficiencyModule = metricsJsModule.recordTokenEfficiency;
recordApiRequestBreakdownModule = metricsJsModule.recordApiRequestBreakdown;
recordPerformanceScoreModule = metricsJsModule.recordPerformanceScore;
recordPerformanceRegressionModule =
metricsJsModule.recordPerformanceRegression;
recordBaselineComparisonModule = metricsJsModule.recordBaselineComparison;
const otelApiModule = await import('@opentelemetry/api');
@@ -124,16 +153,23 @@ describe('Telemetry Metrics', () => {
describe('recordTokenUsageMetrics', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getTelemetryEnabled: () => true,
} as unknown as Config;
it('should not record metrics if not initialized', () => {
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 100, 'input');
recordTokenUsageMetricsModule(mockConfig, 100, {
model: 'gemini-pro',
type: 'input',
});
expect(mockCounterAddFn).not.toHaveBeenCalled();
});
it('should record token usage with the correct attributes', () => {
initializeMetricsModule(mockConfig);
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 100, 'input');
recordTokenUsageMetricsModule(mockConfig, 100, {
model: 'gemini-pro',
type: 'input',
});
expect(mockCounterAddFn).toHaveBeenCalledTimes(2);
expect(mockCounterAddFn).toHaveBeenNthCalledWith(1, 1, {
'session.id': 'test-session-id',
@@ -149,28 +185,40 @@ describe('Telemetry Metrics', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 50, 'output');
recordTokenUsageMetricsModule(mockConfig, 50, {
model: 'gemini-pro',
type: 'output',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(50, {
'session.id': 'test-session-id',
model: 'gemini-pro',
type: 'output',
});
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 25, 'thought');
recordTokenUsageMetricsModule(mockConfig, 25, {
model: 'gemini-pro',
type: 'thought',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(25, {
'session.id': 'test-session-id',
model: 'gemini-pro',
type: 'thought',
});
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 75, 'cache');
recordTokenUsageMetricsModule(mockConfig, 75, {
model: 'gemini-pro',
type: 'cache',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(75, {
'session.id': 'test-session-id',
model: 'gemini-pro',
type: 'cache',
});
recordTokenUsageMetricsModule(mockConfig, 'gemini-pro', 125, 'tool');
recordTokenUsageMetricsModule(mockConfig, 125, {
model: 'gemini-pro',
type: 'tool',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(125, {
'session.id': 'test-session-id',
model: 'gemini-pro',
@@ -182,7 +230,10 @@ describe('Telemetry Metrics', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordTokenUsageMetricsModule(mockConfig, 'gemini-ultra', 200, 'input');
recordTokenUsageMetricsModule(mockConfig, 200, {
model: 'gemini-ultra',
type: 'input',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(200, {
'session.id': 'test-session-id',
model: 'gemini-ultra',
@@ -194,28 +245,27 @@ describe('Telemetry Metrics', () => {
describe('recordFileOperationMetric', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getTelemetryEnabled: () => true,
} as unknown as Config;
it('should not record metrics if not initialized', () => {
recordFileOperationMetricModule(
mockConfig,
FileOperation.CREATE,
10,
'text/plain',
'txt',
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.CREATE,
lines: 10,
mimetype: 'text/plain',
extension: 'txt',
});
expect(mockCounterAddFn).not.toHaveBeenCalled();
});
it('should record file creation with all attributes', () => {
initializeMetricsModule(mockConfig);
recordFileOperationMetricModule(
mockConfig,
FileOperation.CREATE,
10,
'text/plain',
'txt',
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.CREATE,
lines: 10,
mimetype: 'text/plain',
extension: 'txt',
});
expect(mockCounterAddFn).toHaveBeenCalledTimes(2);
expect(mockCounterAddFn).toHaveBeenNthCalledWith(1, 1, {
@@ -234,7 +284,9 @@ describe('Telemetry Metrics', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordFileOperationMetricModule(mockConfig, FileOperation.READ);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.READ,
});
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
operation: FileOperation.READ,
@@ -245,12 +297,10 @@ describe('Telemetry Metrics', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordFileOperationMetricModule(
mockConfig,
FileOperation.UPDATE,
undefined,
'application/javascript',
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.UPDATE,
mimetype: 'application/javascript',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
operation: FileOperation.UPDATE,
@@ -258,48 +308,30 @@ describe('Telemetry Metrics', () => {
});
});
it('should include diffStat when provided', () => {
it('should record file operation without diffStat', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
const diffStat = {
ai_added_lines: 5,
ai_removed_lines: 2,
user_added_lines: 3,
user_removed_lines: 1,
};
recordFileOperationMetricModule(
mockConfig,
FileOperation.UPDATE,
undefined,
undefined,
undefined,
diffStat,
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.UPDATE,
});
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
operation: FileOperation.UPDATE,
ai_added_lines: 5,
ai_removed_lines: 2,
user_added_lines: 3,
user_removed_lines: 1,
});
});
it('should not include diffStat attributes when diffStat is not provided', () => {
it('should record minimal file operation when optional parameters are undefined', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordFileOperationMetricModule(
mockConfig,
FileOperation.UPDATE,
10,
'text/plain',
'txt',
undefined,
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.UPDATE,
lines: 10,
mimetype: 'text/plain',
extension: 'txt',
});
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
@@ -310,33 +342,555 @@ describe('Telemetry Metrics', () => {
});
});
it('should handle diffStat with all zero values', () => {
it('should not include diffStat attributes when diffStat is not provided', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
const diffStat = {
ai_added_lines: 0,
ai_removed_lines: 0,
user_added_lines: 0,
user_removed_lines: 0,
};
recordFileOperationMetricModule(
mockConfig,
FileOperation.UPDATE,
undefined,
undefined,
undefined,
diffStat,
);
recordFileOperationMetricModule(mockConfig, {
operation: FileOperation.UPDATE,
});
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
operation: FileOperation.UPDATE,
ai_added_lines: 0,
ai_removed_lines: 0,
user_added_lines: 0,
user_removed_lines: 0,
});
});
});
describe('Performance Monitoring Metrics', () => {
const mockConfig = {
getSessionId: () => 'test-session-id',
getTelemetryEnabled: () => true,
} as unknown as Config;
describe('recordStartupPerformance', () => {
it('should not record metrics when performance monitoring is disabled', async () => {
// Re-import with performance monitoring disabled by mocking the config
const mockConfigDisabled = {
getSessionId: () => 'test-session-id',
getTelemetryEnabled: () => false, // Disable telemetry to disable performance monitoring
} as unknown as Config;
initializeMetricsModule(mockConfigDisabled);
mockHistogramRecordFn.mockClear();
recordStartupPerformanceModule(mockConfigDisabled, 100, {
phase: 'settings_loading',
details: {
auth_type: 'gemini',
},
});
expect(mockHistogramRecordFn).not.toHaveBeenCalled();
});
it('should record startup performance with phase and details', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordStartupPerformanceModule(mockConfig, 150, {
phase: 'settings_loading',
details: {
auth_type: 'gemini',
telemetry_enabled: true,
settings_sources: 2,
},
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(150, {
'session.id': 'test-session-id',
phase: 'settings_loading',
auth_type: 'gemini',
telemetry_enabled: true,
settings_sources: 2,
});
});
it('should record startup performance without details', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordStartupPerformanceModule(mockConfig, 50, { phase: 'cleanup' });
expect(mockHistogramRecordFn).toHaveBeenCalledWith(50, {
'session.id': 'test-session-id',
phase: 'cleanup',
});
});
it('should handle floating-point duration values from performance.now()', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
// Test with realistic floating-point values that performance.now() would return
const floatingPointDuration = 123.45678;
recordStartupPerformanceModule(mockConfig, floatingPointDuration, {
phase: 'total_startup',
details: {
is_tty: true,
has_question: false,
},
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(
floatingPointDuration,
{
'session.id': 'test-session-id',
phase: 'total_startup',
is_tty: true,
has_question: false,
},
);
});
});
describe('recordMemoryUsage', () => {
it('should record memory usage for different memory types', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordMemoryUsageModule(mockConfig, 15728640, {
memory_type: MemoryMetricType.HEAP_USED,
component: 'startup',
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(15728640, {
'session.id': 'test-session-id',
memory_type: 'heap_used',
component: 'startup',
});
});
it('should record memory usage for all memory metric types', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordMemoryUsageModule(mockConfig, 31457280, {
memory_type: MemoryMetricType.HEAP_TOTAL,
component: 'api_call',
});
recordMemoryUsageModule(mockConfig, 2097152, {
memory_type: MemoryMetricType.EXTERNAL,
component: 'tool_execution',
});
recordMemoryUsageModule(mockConfig, 41943040, {
memory_type: MemoryMetricType.RSS,
component: 'memory_monitor',
});
expect(mockHistogramRecordFn).toHaveBeenCalledTimes(3); // One for each call
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(1, 31457280, {
'session.id': 'test-session-id',
memory_type: 'heap_total',
component: 'api_call',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(2, 2097152, {
'session.id': 'test-session-id',
memory_type: 'external',
component: 'tool_execution',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(3, 41943040, {
'session.id': 'test-session-id',
memory_type: 'rss',
component: 'memory_monitor',
});
});
it('should record memory usage without component', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordMemoryUsageModule(mockConfig, 15728640, {
memory_type: MemoryMetricType.HEAP_USED,
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(15728640, {
'session.id': 'test-session-id',
memory_type: 'heap_used',
});
});
});
describe('recordCpuUsage', () => {
it('should record CPU usage percentage', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordCpuUsageModule(mockConfig, 85.5, {
component: 'tool_execution',
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(85.5, {
'session.id': 'test-session-id',
component: 'tool_execution',
});
});
it('should record CPU usage without component', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordCpuUsageModule(mockConfig, 42.3, {});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(42.3, {
'session.id': 'test-session-id',
});
});
});
describe('recordToolQueueDepth', () => {
it('should record tool queue depth', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordToolQueueDepthModule(mockConfig, 3);
expect(mockHistogramRecordFn).toHaveBeenCalledWith(3, {
'session.id': 'test-session-id',
});
});
it('should record zero queue depth', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordToolQueueDepthModule(mockConfig, 0);
expect(mockHistogramRecordFn).toHaveBeenCalledWith(0, {
'session.id': 'test-session-id',
});
});
});
describe('recordToolExecutionBreakdown', () => {
it('should record tool execution breakdown for all phases', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordToolExecutionBreakdownModule(mockConfig, 25, {
function_name: 'Read',
phase: ToolExecutionPhase.VALIDATION,
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(25, {
'session.id': 'test-session-id',
function_name: 'Read',
phase: 'validation',
});
});
it('should record execution breakdown for different phases', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordToolExecutionBreakdownModule(mockConfig, 50, {
function_name: 'Bash',
phase: ToolExecutionPhase.PREPARATION,
});
recordToolExecutionBreakdownModule(mockConfig, 1500, {
function_name: 'Bash',
phase: ToolExecutionPhase.EXECUTION,
});
recordToolExecutionBreakdownModule(mockConfig, 75, {
function_name: 'Bash',
phase: ToolExecutionPhase.RESULT_PROCESSING,
});
expect(mockHistogramRecordFn).toHaveBeenCalledTimes(3); // One for each call
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(1, 50, {
'session.id': 'test-session-id',
function_name: 'Bash',
phase: 'preparation',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(2, 1500, {
'session.id': 'test-session-id',
function_name: 'Bash',
phase: 'execution',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(3, 75, {
'session.id': 'test-session-id',
function_name: 'Bash',
phase: 'result_processing',
});
});
});
describe('recordTokenEfficiency', () => {
it('should record token efficiency metrics', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordTokenEfficiencyModule(mockConfig, 0.85, {
model: 'gemini-pro',
metric: 'cache_hit_rate',
context: 'api_request',
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(0.85, {
'session.id': 'test-session-id',
model: 'gemini-pro',
metric: 'cache_hit_rate',
context: 'api_request',
});
});
it('should record token efficiency without context', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordTokenEfficiencyModule(mockConfig, 125.5, {
model: 'gemini-pro',
metric: 'tokens_per_operation',
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(125.5, {
'session.id': 'test-session-id',
model: 'gemini-pro',
metric: 'tokens_per_operation',
});
});
});
describe('recordApiRequestBreakdown', () => {
it('should record API request breakdown for all phases', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordApiRequestBreakdownModule(mockConfig, 15, {
model: 'gemini-pro',
phase: ApiRequestPhase.REQUEST_PREPARATION,
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(15, {
'session.id': 'test-session-id',
model: 'gemini-pro',
phase: 'request_preparation',
});
});
it('should record API request breakdown for different phases', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordApiRequestBreakdownModule(mockConfig, 250, {
model: 'gemini-pro',
phase: ApiRequestPhase.NETWORK_LATENCY,
});
recordApiRequestBreakdownModule(mockConfig, 100, {
model: 'gemini-pro',
phase: ApiRequestPhase.RESPONSE_PROCESSING,
});
recordApiRequestBreakdownModule(mockConfig, 50, {
model: 'gemini-pro',
phase: ApiRequestPhase.TOKEN_PROCESSING,
});
expect(mockHistogramRecordFn).toHaveBeenCalledTimes(3); // One for each call
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(1, 250, {
'session.id': 'test-session-id',
model: 'gemini-pro',
phase: 'network_latency',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(2, 100, {
'session.id': 'test-session-id',
model: 'gemini-pro',
phase: 'response_processing',
});
expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(3, 50, {
'session.id': 'test-session-id',
model: 'gemini-pro',
phase: 'token_processing',
});
});
});
describe('recordPerformanceScore', () => {
it('should record performance score with category and baseline', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordPerformanceScoreModule(mockConfig, 85.5, {
category: 'memory_efficiency',
baseline: 80.0,
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(85.5, {
'session.id': 'test-session-id',
category: 'memory_efficiency',
baseline: 80.0,
});
});
it('should record performance score without baseline', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordPerformanceScoreModule(mockConfig, 92.3, {
category: 'overall_performance',
});
expect(mockHistogramRecordFn).toHaveBeenCalledWith(92.3, {
'session.id': 'test-session-id',
category: 'overall_performance',
});
});
});
describe('recordPerformanceRegression', () => {
it('should record performance regression with baseline comparison', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
mockHistogramRecordFn.mockClear();
recordPerformanceRegressionModule(mockConfig, {
metric: 'startup_time',
current_value: 1200,
baseline_value: 1000,
severity: 'medium',
});
// Verify regression counter
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
metric: 'startup_time',
severity: 'medium',
current_value: 1200,
baseline_value: 1000,
});
// Verify baseline comparison histogram (20% increase)
expect(mockHistogramRecordFn).toHaveBeenCalledWith(20, {
'session.id': 'test-session-id',
metric: 'startup_time',
severity: 'medium',
current_value: 1200,
baseline_value: 1000,
});
});
it('should handle zero baseline value gracefully', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
mockHistogramRecordFn.mockClear();
recordPerformanceRegressionModule(mockConfig, {
metric: 'memory_usage',
current_value: 100,
baseline_value: 0,
severity: 'high',
});
// Verify regression counter still recorded
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
metric: 'memory_usage',
severity: 'high',
current_value: 100,
baseline_value: 0,
});
// Verify no baseline comparison due to zero baseline
expect(mockHistogramRecordFn).not.toHaveBeenCalled();
});
it('should record different severity levels', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
recordPerformanceRegressionModule(mockConfig, {
metric: 'api_latency',
current_value: 500,
baseline_value: 400,
severity: 'low',
});
recordPerformanceRegressionModule(mockConfig, {
metric: 'cpu_usage',
current_value: 90,
baseline_value: 70,
severity: 'high',
});
expect(mockCounterAddFn).toHaveBeenNthCalledWith(1, 1, {
'session.id': 'test-session-id',
metric: 'api_latency',
severity: 'low',
current_value: 500,
baseline_value: 400,
});
expect(mockCounterAddFn).toHaveBeenNthCalledWith(2, 1, {
'session.id': 'test-session-id',
metric: 'cpu_usage',
severity: 'high',
current_value: 90,
baseline_value: 70,
});
});
});
describe('recordBaselineComparison', () => {
it('should record baseline comparison with percentage change', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordBaselineComparisonModule(mockConfig, {
metric: 'memory_usage',
current_value: 120,
baseline_value: 100,
category: 'performance_tracking',
});
// 20% increase: (120 - 100) / 100 * 100 = 20%
expect(mockHistogramRecordFn).toHaveBeenCalledWith(20, {
'session.id': 'test-session-id',
metric: 'memory_usage',
category: 'performance_tracking',
current_value: 120,
baseline_value: 100,
});
});
it('should handle negative percentage change (improvement)', () => {
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordBaselineComparisonModule(mockConfig, {
metric: 'startup_time',
current_value: 800,
baseline_value: 1000,
category: 'optimization',
});
// 20% decrease: (800 - 1000) / 1000 * 100 = -20%
expect(mockHistogramRecordFn).toHaveBeenCalledWith(-20, {
'session.id': 'test-session-id',
metric: 'startup_time',
category: 'optimization',
current_value: 800,
baseline_value: 1000,
});
});
it('should skip recording when baseline is zero', async () => {
// Access the actual mocked module
const mockedModule = (await vi.importMock('@opentelemetry/api')) as {
diag: { warn: ReturnType<typeof vi.fn> };
};
const diagSpy = vi.spyOn(mockedModule.diag, 'warn');
initializeMetricsModule(mockConfig);
mockHistogramRecordFn.mockClear();
recordBaselineComparisonModule(mockConfig, {
metric: 'new_metric',
current_value: 50,
baseline_value: 0,
category: 'testing',
});
expect(diagSpy).toHaveBeenCalledWith(
'Baseline value is zero, skipping comparison.',
);
expect(mockHistogramRecordFn).not.toHaveBeenCalled();
});
});
});

722
packages/core/src/telemetry/metrics.ts
View File

@@ -5,24 +5,282 @@
*/
import type { Attributes, Meter, Counter, Histogram } from '@opentelemetry/api';
import { metrics, ValueType } from '@opentelemetry/api';
import {
SERVICE_NAME,
METRIC_TOOL_CALL_COUNT,
METRIC_TOOL_CALL_LATENCY,
METRIC_API_REQUEST_COUNT,
METRIC_API_REQUEST_LATENCY,
METRIC_TOKEN_USAGE,
METRIC_SESSION_COUNT,
METRIC_FILE_OPERATION_COUNT,
EVENT_CHAT_COMPRESSION,
METRIC_INVALID_CHUNK_COUNT,
METRIC_CONTENT_RETRY_COUNT,
METRIC_CONTENT_RETRY_FAILURE_COUNT,
METRIC_SUBAGENT_EXECUTION_COUNT,
} from './constants.js';
import { diag, metrics, ValueType } from '@opentelemetry/api';
import { SERVICE_NAME, EVENT_CHAT_COMPRESSION } from './constants.js';
import type { Config } from '../config/config.js';
import type { DiffStat } from '../tools/tools.js';
import type { ModelSlashCommandEvent } from './types.js';
const TOOL_CALL_COUNT = `${SERVICE_NAME}.tool.call.count`;
const TOOL_CALL_LATENCY = `${SERVICE_NAME}.tool.call.latency`;
const API_REQUEST_COUNT = `${SERVICE_NAME}.api.request.count`;
const API_REQUEST_LATENCY = `${SERVICE_NAME}.api.request.latency`;
const TOKEN_USAGE = `${SERVICE_NAME}.token.usage`;
const SESSION_COUNT = `${SERVICE_NAME}.session.count`;
const FILE_OPERATION_COUNT = `${SERVICE_NAME}.file.operation.count`;
const INVALID_CHUNK_COUNT = `${SERVICE_NAME}.chat.invalid_chunk.count`;
const CONTENT_RETRY_COUNT = `${SERVICE_NAME}.chat.content_retry.count`;
const CONTENT_RETRY_FAILURE_COUNT = `${SERVICE_NAME}.chat.content_retry_failure.count`;
const MODEL_SLASH_COMMAND_CALL_COUNT = `${SERVICE_NAME}.slash_command.model.call_count`;
export const SUBAGENT_EXECUTION_COUNT = `${SERVICE_NAME}.subagent.execution.count`;
// Performance Monitoring Metrics
const STARTUP_TIME = `${SERVICE_NAME}.startup.duration`;
const MEMORY_USAGE = `${SERVICE_NAME}.memory.usage`;
const CPU_USAGE = `${SERVICE_NAME}.cpu.usage`;
const TOOL_QUEUE_DEPTH = `${SERVICE_NAME}.tool.queue.depth`;
const TOOL_EXECUTION_BREAKDOWN = `${SERVICE_NAME}.tool.execution.breakdown`;
const TOKEN_EFFICIENCY = `${SERVICE_NAME}.token.efficiency`;
const API_REQUEST_BREAKDOWN = `${SERVICE_NAME}.api.request.breakdown`;
const PERFORMANCE_SCORE = `${SERVICE_NAME}.performance.score`;
const REGRESSION_DETECTION = `${SERVICE_NAME}.performance.regression`;
const REGRESSION_PERCENTAGE_CHANGE = `${SERVICE_NAME}.performance.regression.percentage_change`;
const BASELINE_COMPARISON = `${SERVICE_NAME}.performance.baseline.comparison`;
const baseMetricDefinition = {
getCommonAttributes: (config: Config): Attributes => ({
'session.id': config.getSessionId(),
}),
};
const COUNTER_DEFINITIONS = {
[TOOL_CALL_COUNT]: {
description: 'Counts tool calls, tagged by function name and success.',
valueType: ValueType.INT,
assign: (c: Counter) => (toolCallCounter = c),
attributes: {} as {
function_name: string;
success: boolean;
decision?: 'accept' | 'reject' | 'modify' | 'auto_accept';
tool_type?: 'native' | 'mcp';
},
},
[API_REQUEST_COUNT]: {
description: 'Counts API requests, tagged by model and status.',
valueType: ValueType.INT,
assign: (c: Counter) => (apiRequestCounter = c),
attributes: {} as {
model: string;
status_code?: number | string;
error_type?: string;
},
},
[TOKEN_USAGE]: {
description: 'Counts the total number of tokens used.',
valueType: ValueType.INT,
assign: (c: Counter) => (tokenUsageCounter = c),
attributes: {} as {
model: string;
type: 'input' | 'output' | 'thought' | 'cache' | 'tool';
},
},
[SESSION_COUNT]: {
description: 'Count of CLI sessions started.',
valueType: ValueType.INT,
assign: (c: Counter) => (sessionCounter = c),
attributes: {} as Record<string, never>,
},
[FILE_OPERATION_COUNT]: {
description: 'Counts file operations (create, read, update).',
valueType: ValueType.INT,
assign: (c: Counter) => (fileOperationCounter = c),
attributes: {} as {
operation: FileOperation;
lines?: number;
mimetype?: string;
extension?: string;
programming_language?: string;
},
},
[INVALID_CHUNK_COUNT]: {
description: 'Counts invalid chunks received from a stream.',
valueType: ValueType.INT,
assign: (c: Counter) => (invalidChunkCounter = c),
attributes: {} as Record<string, never>,
},
[CONTENT_RETRY_COUNT]: {
description: 'Counts retries due to content errors (e.g., empty stream).',
valueType: ValueType.INT,
assign: (c: Counter) => (contentRetryCounter = c),
attributes: {} as Record<string, never>,
},
[CONTENT_RETRY_FAILURE_COUNT]: {
description: 'Counts occurrences of all content retries failing.',
valueType: ValueType.INT,
assign: (c: Counter) => (contentRetryFailureCounter = c),
attributes: {} as Record<string, never>,
},
[MODEL_SLASH_COMMAND_CALL_COUNT]: {
description: 'Counts model slash command calls.',
valueType: ValueType.INT,
assign: (c: Counter) => (modelSlashCommandCallCounter = c),
attributes: {} as {
'slash_command.model.model_name': string;
},
},
[EVENT_CHAT_COMPRESSION]: {
description: 'Counts chat compression events.',
valueType: ValueType.INT,
assign: (c: Counter) => (chatCompressionCounter = c),
attributes: {} as {
tokens_before: number;
tokens_after: number;
},
},
} as const;
const HISTOGRAM_DEFINITIONS = {
[TOOL_CALL_LATENCY]: {
description: 'Latency of tool calls in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
assign: (h: Histogram) => (toolCallLatencyHistogram = h),
attributes: {} as {
function_name: string;
},
},
[API_REQUEST_LATENCY]: {
description: 'Latency of API requests in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
assign: (h: Histogram) => (apiRequestLatencyHistogram = h),
attributes: {} as {
model: string;
},
},
} as const;
const PERFORMANCE_COUNTER_DEFINITIONS = {
[REGRESSION_DETECTION]: {
description: 'Performance regression detection events.',
valueType: ValueType.INT,
assign: (c: Counter) => (regressionDetectionCounter = c),
attributes: {} as {
metric: string;
severity: 'low' | 'medium' | 'high';
current_value: number;
baseline_value: number;
},
},
} as const;
const PERFORMANCE_HISTOGRAM_DEFINITIONS = {
[STARTUP_TIME]: {
description:
'CLI startup time in milliseconds, broken down by initialization phase.',
unit: 'ms',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (startupTimeHistogram = h),
attributes: {} as {
phase: string;
details?: Record<string, string | number | boolean>;
},
},
[MEMORY_USAGE]: {
description: 'Memory usage in bytes.',
unit: 'bytes',
valueType: ValueType.INT,
assign: (h: Histogram) => (memoryUsageGauge = h),
attributes: {} as {
memory_type: MemoryMetricType;
component?: string;
},
},
[CPU_USAGE]: {
description: 'CPU usage percentage.',
unit: 'percent',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (cpuUsageGauge = h),
attributes: {} as {
component?: string;
},
},
[TOOL_QUEUE_DEPTH]: {
description: 'Number of tools in execution queue.',
unit: 'count',
valueType: ValueType.INT,
assign: (h: Histogram) => (toolQueueDepthGauge = h),
attributes: {} as Record<string, never>,
},
[TOOL_EXECUTION_BREAKDOWN]: {
description: 'Tool execution time breakdown by phase in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
assign: (h: Histogram) => (toolExecutionBreakdownHistogram = h),
attributes: {} as {
function_name: string;
phase: ToolExecutionPhase;
},
},
[TOKEN_EFFICIENCY]: {
description:
'Token efficiency metrics (tokens per operation, cache hit rate, etc.).',
unit: 'ratio',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (tokenEfficiencyHistogram = h),
attributes: {} as {
model: string;
metric: string;
context?: string;
},
},
[API_REQUEST_BREAKDOWN]: {
description: 'API request time breakdown by phase in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
assign: (h: Histogram) => (apiRequestBreakdownHistogram = h),
attributes: {} as {
model: string;
phase: ApiRequestPhase;
},
},
[PERFORMANCE_SCORE]: {
description: 'Composite performance score (0-100).',
unit: 'score',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (performanceScoreGauge = h),
attributes: {} as {
category: string;
baseline?: number;
},
},
[REGRESSION_PERCENTAGE_CHANGE]: {
description:
'Percentage change compared to baseline for detected regressions.',
unit: 'percent',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (regressionPercentageChangeHistogram = h),
attributes: {} as {
metric: string;
severity: 'low' | 'medium' | 'high';
current_value: number;
baseline_value: number;
},
},
[BASELINE_COMPARISON]: {
description:
'Performance comparison to established baseline (percentage change).',
unit: 'percent',
valueType: ValueType.DOUBLE,
assign: (h: Histogram) => (baselineComparisonHistogram = h),
attributes: {} as {
metric: string;
category: string;
current_value: number;
baseline_value: number;
},
},
} as const;
type AllMetricDefs = typeof COUNTER_DEFINITIONS &
typeof HISTOGRAM_DEFINITIONS &
typeof PERFORMANCE_COUNTER_DEFINITIONS &
typeof PERFORMANCE_HISTOGRAM_DEFINITIONS;
export type MetricDefinitions = {
[K in keyof AllMetricDefs]: {
attributes: AllMetricDefs[K]['attributes'];
};
};
export enum FileOperation {
CREATE = 'create',
@@ -30,25 +288,65 @@ export enum FileOperation {
UPDATE = 'update',
}
export enum PerformanceMetricType {
STARTUP = 'startup',
MEMORY = 'memory',
CPU = 'cpu',
TOOL_EXECUTION = 'tool_execution',
API_REQUEST = 'api_request',
TOKEN_EFFICIENCY = 'token_efficiency',
}
export enum MemoryMetricType {
HEAP_USED = 'heap_used',
HEAP_TOTAL = 'heap_total',
EXTERNAL = 'external',
RSS = 'rss',
}
export enum ToolExecutionPhase {
VALIDATION = 'validation',
PREPARATION = 'preparation',
EXECUTION = 'execution',
RESULT_PROCESSING = 'result_processing',
}
export enum ApiRequestPhase {
REQUEST_PREPARATION = 'request_preparation',
NETWORK_LATENCY = 'network_latency',
RESPONSE_PROCESSING = 'response_processing',
TOKEN_PROCESSING = 'token_processing',
}
let cliMeter: Meter | undefined;
let toolCallCounter: Counter | undefined;
let toolCallLatencyHistogram: Histogram | undefined;
let apiRequestCounter: Counter | undefined;
let apiRequestLatencyHistogram: Histogram | undefined;
let tokenUsageCounter: Counter | undefined;
let sessionCounter: Counter | undefined;
let fileOperationCounter: Counter | undefined;
let chatCompressionCounter: Counter | undefined;
let invalidChunkCounter: Counter | undefined;
let contentRetryCounter: Counter | undefined;
let contentRetryFailureCounter: Counter | undefined;
let subagentExecutionCounter: Counter | undefined;
let isMetricsInitialized = false;
let modelSlashCommandCallCounter: Counter | undefined;
function getCommonAttributes(config: Config): Attributes {
return {
'session.id': config.getSessionId(),
};
}
// Performance Monitoring Metrics
let startupTimeHistogram: Histogram | undefined;
let memoryUsageGauge: Histogram | undefined; // Using Histogram until ObservableGauge is available
let cpuUsageGauge: Histogram | undefined;
let toolQueueDepthGauge: Histogram | undefined;
let toolExecutionBreakdownHistogram: Histogram | undefined;
let tokenEfficiencyHistogram: Histogram | undefined;
let apiRequestBreakdownHistogram: Histogram | undefined;
let performanceScoreGauge: Histogram | undefined;
let regressionDetectionCounter: Counter | undefined;
let regressionPercentageChangeHistogram: Histogram | undefined;
let baselineComparisonHistogram: Histogram | undefined;
let isMetricsInitialized = false;
let isPerformanceMonitoringEnabled = false;
export function getMeter(): Meter | undefined {
if (!cliMeter) {
@@ -63,129 +361,79 @@ export function initializeMetrics(config: Config): void {
const meter = getMeter();
if (!meter) return;
toolCallCounter = meter.createCounter(METRIC_TOOL_CALL_COUNT, {
description: 'Counts tool calls, tagged by function name and success.',
valueType: ValueType.INT,
});
toolCallLatencyHistogram = meter.createHistogram(METRIC_TOOL_CALL_LATENCY, {
description: 'Latency of tool calls in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
});
apiRequestCounter = meter.createCounter(METRIC_API_REQUEST_COUNT, {
description: 'Counts API requests, tagged by model and status.',
valueType: ValueType.INT,
});
apiRequestLatencyHistogram = meter.createHistogram(
METRIC_API_REQUEST_LATENCY,
{
description: 'Latency of API requests in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
// Initialize core metrics
Object.entries(COUNTER_DEFINITIONS).forEach(
([name, { description, valueType, assign }]) => {
assign(meter.createCounter(name, { description, valueType }));
},
);
tokenUsageCounter = meter.createCounter(METRIC_TOKEN_USAGE, {
description: 'Counts the total number of tokens used.',
valueType: ValueType.INT,
});
fileOperationCounter = meter.createCounter(METRIC_FILE_OPERATION_COUNT, {
description: 'Counts file operations (create, read, update).',
valueType: ValueType.INT,
});
chatCompressionCounter = meter.createCounter(EVENT_CHAT_COMPRESSION, {
description: 'Counts chat compression events.',
subagentExecutionCounter = meter.createCounter(SUBAGENT_EXECUTION_COUNT, {
description:
'Counts subagent execution events, tagged by status and subagent name.',
valueType: ValueType.INT,
});
// New counters for content errors
invalidChunkCounter = meter.createCounter(METRIC_INVALID_CHUNK_COUNT, {
description: 'Counts invalid chunks received from a stream.',
valueType: ValueType.INT,
});
contentRetryCounter = meter.createCounter(METRIC_CONTENT_RETRY_COUNT, {
description: 'Counts retries due to content errors (e.g., empty stream).',
valueType: ValueType.INT,
});
contentRetryFailureCounter = meter.createCounter(
METRIC_CONTENT_RETRY_FAILURE_COUNT,
{
description: 'Counts occurrences of all content retries failing.',
valueType: ValueType.INT,
},
);
subagentExecutionCounter = meter.createCounter(
METRIC_SUBAGENT_EXECUTION_COUNT,
{
description:
'Counts subagent execution events, tagged by status and subagent name.',
valueType: ValueType.INT,
Object.entries(HISTOGRAM_DEFINITIONS).forEach(
([name, { description, unit, valueType, assign }]) => {
assign(meter.createHistogram(name, { description, unit, valueType }));
},
);
const sessionCounter = meter.createCounter(METRIC_SESSION_COUNT, {
description: 'Count of CLI sessions started.',
valueType: ValueType.INT,
});
sessionCounter.add(1, getCommonAttributes(config));
// Increment session counter after all metrics are initialized
sessionCounter?.add(1, baseMetricDefinition.getCommonAttributes(config));
// Initialize performance monitoring metrics if enabled
initializePerformanceMonitoring(config);
isMetricsInitialized = true;
}
export function recordChatCompressionMetrics(
config: Config,
args: { tokens_before: number; tokens_after: number },
attributes: MetricDefinitions[typeof EVENT_CHAT_COMPRESSION]['attributes'],
) {
if (!chatCompressionCounter || !isMetricsInitialized) return;
chatCompressionCounter.add(1, {
...getCommonAttributes(config),
...args,
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
});
}
export function recordToolCallMetrics(
config: Config,
functionName: string,
durationMs: number,
success: boolean,
decision?: 'accept' | 'reject' | 'modify' | 'auto_accept',
tool_type?: 'native' | 'mcp',
attributes: MetricDefinitions[typeof TOOL_CALL_COUNT]['attributes'],
): void {
if (!toolCallCounter || !toolCallLatencyHistogram || !isMetricsInitialized)
return;
const metricAttributes: Attributes = {
...getCommonAttributes(config),
function_name: functionName,
success,
decision,
tool_type,
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
toolCallCounter.add(1, metricAttributes);
toolCallLatencyHistogram.record(durationMs, {
...getCommonAttributes(config),
function_name: functionName,
...baseMetricDefinition.getCommonAttributes(config),
function_name: attributes.function_name,
});
}
export function recordTokenUsageMetrics(
config: Config,
model: string,
tokenCount: number,
type: 'input' | 'output' | 'thought' | 'cache' | 'tool',
attributes: MetricDefinitions[typeof TOKEN_USAGE]['attributes'],
): void {
if (!tokenUsageCounter || !isMetricsInitialized) return;
tokenUsageCounter.add(tokenCount, {
...getCommonAttributes(config),
model,
type,
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
});
}
export function recordApiResponseMetrics(
config: Config,
model: string,
durationMs: number,
statusCode?: number | string,
error?: string,
attributes: MetricDefinitions[typeof API_REQUEST_COUNT]['attributes'],
): void {
if (
!apiRequestCounter ||
@@ -194,23 +442,21 @@ export function recordApiResponseMetrics(
)
return;
const metricAttributes: Attributes = {
...getCommonAttributes(config),
model,
status_code: statusCode ?? (error ? 'error' : 'ok'),
...baseMetricDefinition.getCommonAttributes(config),
model: attributes.model,
status_code: attributes.status_code ?? 'ok',
};
apiRequestCounter.add(1, metricAttributes);
apiRequestLatencyHistogram.record(durationMs, {
...getCommonAttributes(config),
model,
...baseMetricDefinition.getCommonAttributes(config),
model: attributes.model,
});
}
export function recordApiErrorMetrics(
config: Config,
model: string,
durationMs: number,
statusCode?: number | string,
errorType?: string,
attributes: MetricDefinitions[typeof API_REQUEST_COUNT]['attributes'],
): void {
if (
!apiRequestCounter ||
@@ -219,45 +465,27 @@ export function recordApiErrorMetrics(
)
return;
const metricAttributes: Attributes = {
...getCommonAttributes(config),
model,
status_code: statusCode ?? 'error',
error_type: errorType ?? 'unknown',
...baseMetricDefinition.getCommonAttributes(config),
model: attributes.model,
status_code: attributes.status_code ?? 'error',
error_type: attributes.error_type ?? 'unknown',
};
apiRequestCounter.add(1, metricAttributes);
apiRequestLatencyHistogram.record(durationMs, {
...getCommonAttributes(config),
model,
...baseMetricDefinition.getCommonAttributes(config),
model: attributes.model,
});
}
export function recordFileOperationMetric(
config: Config,
operation: FileOperation,
lines?: number,
mimetype?: string,
extension?: string,
diffStat?: DiffStat,
programming_language?: string,
attributes: MetricDefinitions[typeof FILE_OPERATION_COUNT]['attributes'],
): void {
if (!fileOperationCounter || !isMetricsInitialized) return;
const attributes: Attributes = {
...getCommonAttributes(config),
operation,
};
if (lines !== undefined) attributes['lines'] = lines;
if (mimetype !== undefined) attributes['mimetype'] = mimetype;
if (extension !== undefined) attributes['extension'] = extension;
if (diffStat !== undefined) {
attributes['ai_added_lines'] = diffStat.ai_added_lines;
attributes['ai_removed_lines'] = diffStat.ai_removed_lines;
attributes['user_added_lines'] = diffStat.user_added_lines;
attributes['user_removed_lines'] = diffStat.user_removed_lines;
}
if (programming_language !== undefined) {
attributes['programming_language'] = programming_language;
}
fileOperationCounter.add(1, attributes);
fileOperationCounter.add(1, {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
});
}
// --- New Metric Recording Functions ---
@@ -267,7 +495,7 @@ export function recordFileOperationMetric(
*/
export function recordInvalidChunk(config: Config): void {
if (!invalidChunkCounter || !isMetricsInitialized) return;
invalidChunkCounter.add(1, getCommonAttributes(config));
invalidChunkCounter.add(1, baseMetricDefinition.getCommonAttributes(config));
}
/**
@@ -275,7 +503,7 @@ export function recordInvalidChunk(config: Config): void {
*/
export function recordContentRetry(config: Config): void {
if (!contentRetryCounter || !isMetricsInitialized) return;
contentRetryCounter.add(1, getCommonAttributes(config));
contentRetryCounter.add(1, baseMetricDefinition.getCommonAttributes(config));
}
/**
@@ -283,7 +511,217 @@ export function recordContentRetry(config: Config): void {
*/
export function recordContentRetryFailure(config: Config): void {
if (!contentRetryFailureCounter || !isMetricsInitialized) return;
contentRetryFailureCounter.add(1, getCommonAttributes(config));
contentRetryFailureCounter.add(
1,
baseMetricDefinition.getCommonAttributes(config),
);
}
export function recordModelSlashCommand(
config: Config,
event: ModelSlashCommandEvent,
): void {
if (!modelSlashCommandCallCounter || !isMetricsInitialized) return;
modelSlashCommandCallCounter.add(1, {
...baseMetricDefinition.getCommonAttributes(config),
'slash_command.model.model_name': event.model_name,
});
}
// Performance Monitoring Functions
export function initializePerformanceMonitoring(config: Config): void {
const meter = getMeter();
if (!meter) return;
// Check if performance monitoring is enabled in config
// For now, enable performance monitoring when telemetry is enabled
// TODO: Add specific performance monitoring settings to config
isPerformanceMonitoringEnabled = config.getTelemetryEnabled();
if (!isPerformanceMonitoringEnabled) return;
Object.entries(PERFORMANCE_COUNTER_DEFINITIONS).forEach(
([name, { description, valueType, assign }]) => {
assign(meter.createCounter(name, { description, valueType }));
},
);
Object.entries(PERFORMANCE_HISTOGRAM_DEFINITIONS).forEach(
([name, { description, unit, valueType, assign }]) => {
assign(meter.createHistogram(name, { description, unit, valueType }));
},
);
}
export function recordStartupPerformance(
config: Config,
durationMs: number,
attributes: MetricDefinitions[typeof STARTUP_TIME]['attributes'],
): void {
if (!startupTimeHistogram || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
phase: attributes.phase,
...attributes.details,
};
startupTimeHistogram.record(durationMs, metricAttributes);
}
export function recordMemoryUsage(
config: Config,
bytes: number,
attributes: MetricDefinitions[typeof MEMORY_USAGE]['attributes'],
): void {
if (!memoryUsageGauge || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
memoryUsageGauge.record(bytes, metricAttributes);
}
export function recordCpuUsage(
config: Config,
percentage: number,
attributes: MetricDefinitions[typeof CPU_USAGE]['attributes'],
): void {
if (!cpuUsageGauge || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
cpuUsageGauge.record(percentage, metricAttributes);
}
export function recordToolQueueDepth(config: Config, queueDepth: number): void {
if (!toolQueueDepthGauge || !isPerformanceMonitoringEnabled) return;
const attributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
};
toolQueueDepthGauge.record(queueDepth, attributes);
}
export function recordToolExecutionBreakdown(
config: Config,
durationMs: number,
attributes: MetricDefinitions[typeof TOOL_EXECUTION_BREAKDOWN]['attributes'],
): void {
if (!toolExecutionBreakdownHistogram || !isPerformanceMonitoringEnabled)
return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
toolExecutionBreakdownHistogram.record(durationMs, metricAttributes);
}
export function recordTokenEfficiency(
config: Config,
value: number,
attributes: MetricDefinitions[typeof TOKEN_EFFICIENCY]['attributes'],
): void {
if (!tokenEfficiencyHistogram || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
tokenEfficiencyHistogram.record(value, metricAttributes);
}
export function recordApiRequestBreakdown(
config: Config,
durationMs: number,
attributes: MetricDefinitions[typeof API_REQUEST_BREAKDOWN]['attributes'],
): void {
if (!apiRequestBreakdownHistogram || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
apiRequestBreakdownHistogram.record(durationMs, metricAttributes);
}
export function recordPerformanceScore(
config: Config,
score: number,
attributes: MetricDefinitions[typeof PERFORMANCE_SCORE]['attributes'],
): void {
if (!performanceScoreGauge || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
performanceScoreGauge.record(score, metricAttributes);
}
export function recordPerformanceRegression(
config: Config,
attributes: MetricDefinitions[typeof REGRESSION_DETECTION]['attributes'],
): void {
if (!regressionDetectionCounter || !isPerformanceMonitoringEnabled) return;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
regressionDetectionCounter.add(1, metricAttributes);
if (attributes.baseline_value !== 0 && regressionPercentageChangeHistogram) {
const percentageChange =
((attributes.current_value - attributes.baseline_value) /
attributes.baseline_value) *
100;
regressionPercentageChangeHistogram.record(
percentageChange,
metricAttributes,
);
}
}
export function recordBaselineComparison(
config: Config,
attributes: MetricDefinitions[typeof BASELINE_COMPARISON]['attributes'],
): void {
if (!baselineComparisonHistogram || !isPerformanceMonitoringEnabled) return;
if (attributes.baseline_value === 0) {
diag.warn('Baseline value is zero, skipping comparison.');
return;
}
const percentageChange =
((attributes.current_value - attributes.baseline_value) /
attributes.baseline_value) *
100;
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
...attributes,
};
baselineComparisonHistogram.record(percentageChange, metricAttributes);
}
// Utility function to check if performance monitoring is enabled
export function isPerformanceMonitoringActive(): boolean {
return isPerformanceMonitoringEnabled && isMetricsInitialized;
}
/**
@@ -298,7 +736,7 @@ export function recordSubagentExecutionMetrics(
if (!subagentExecutionCounter || !isMetricsInitialized) return;
const attributes: Attributes = {
...getCommonAttributes(config),
...baseMetricDefinition.getCommonAttributes(config),
subagent_name: subagentName,
status,
};

3
packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts
View File

@@ -55,6 +55,7 @@ const makeFakeConfig = (overrides: Partial<Config> = {}): Config => {
getTelemetryEnabled: () => true,
getTelemetryLogPromptsEnabled: () => false,
getFileFilteringRespectGitIgnore: () => true,
getOutputFormat: () => 'text',
...overrides,
};
return defaults as Config;
@@ -262,7 +263,7 @@ describe('QwenLogger', () => {
expect(enqueueSpy).toHaveBeenCalledWith(
expect.objectContaining({
event_type: 'action',
type: 'connection',
type: 'ide',
name: 'ide_connection',
snapshots: JSON.stringify({
connection_type: IdeConnectionType.SESSION,

456
packages/core/src/telemetry/qwen-logger/qwen-logger.ts
View File

@@ -30,6 +30,12 @@ import type {
ContentRetryFailureEvent,
ConversationFinishedEvent,
SubagentExecutionEvent,
ExtensionInstallEvent,
ExtensionUninstallEvent,
ToolOutputTruncatedEvent,
ExtensionEnableEvent,
ModelSlashCommandEvent,
ExtensionDisableEvent,
} from '../types.js';
import { EndSessionEvent } from '../types.js';
import type {
@@ -237,7 +243,7 @@ export class QwenLogger {
model: this.config?.getModel(),
base_url:
authType === AuthType.USE_OPENAI
? process.env['OPENAI_BASE_URL']
? this.config?.getContentGeneratorConfig().baseUrl || ''
: '',
},
_v: `qwen-code@${version}`,
@@ -324,7 +330,7 @@ export class QwenLogger {
await retryWithBackoff(flushFn, {
maxAttempts: 3,
initialDelayMs: 200,
shouldRetry: (err: unknown) => {
shouldRetryOnError: (err: unknown) => {
if (!(err instanceof Error)) return false;
const status = (err as HttpError).status as number | undefined;
// If status is not available, it's likely a network error
@@ -361,6 +367,7 @@ export class QwenLogger {
}
}
// session events
logStartSessionEvent(event: StartSessionEvent): void {
const applicationEvent = this.createViewEvent('session', 'session_start', {
properties: {
@@ -390,8 +397,37 @@ export class QwenLogger {
});
}
logEndSessionEvent(_event: EndSessionEvent): void {
const applicationEvent = this.createViewEvent('session', 'session_end', {});
// Flush immediately on session end.
this.enqueueLogEvent(applicationEvent);
this.flushToRum().catch((error: unknown) => {
if (this.config?.getDebugMode()) {
console.debug('Error flushing to RUM:', error);
}
});
}
logConversationFinishedEvent(event: ConversationFinishedEvent): void {
const rumEvent = this.createActionEvent(
'conversation',
'conversation_finished',
{
snapshots: JSON.stringify({
approval_mode: event.approvalMode,
turn_count: event.turnCount,
}),
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// user action events
logNewPromptEvent(event: UserPromptEvent): void {
const rumEvent = this.createActionEvent('user_prompt', 'user_prompt', {
const rumEvent = this.createActionEvent('user', 'new_prompt', {
properties: {
auth_type: event.auth_type,
prompt_id: event.prompt_id,
@@ -405,9 +441,33 @@ export class QwenLogger {
this.flushIfNeeded();
}
logSlashCommandEvent(event: SlashCommandEvent): void {
const rumEvent = this.createActionEvent('user', 'slash_command', {
snapshots: JSON.stringify({
command: event.command,
subcommand: event.subcommand,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logModelSlashCommandEvent(event: ModelSlashCommandEvent): void {
const rumEvent = this.createActionEvent('user', 'model_slash_command', {
snapshots: JSON.stringify({
model_name: event.model_name,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// tool call events
logToolCallEvent(event: ToolCallEvent): void {
const rumEvent = this.createActionEvent(
'tool_call',
'tool',
`tool_call#${event.function_name}`,
{
properties: {
@@ -429,35 +489,19 @@ export class QwenLogger {
this.flushIfNeeded();
}
logApiCancelEvent(event: ApiCancelEvent): void {
const rumEvent = this.createActionEvent('api', 'api_cancel', {
properties: {
model: event.model,
prompt_id: event.prompt_id,
auth_type: event.auth_type,
},
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logFileOperationEvent(event: FileOperationEvent): void {
const rumEvent = this.createActionEvent(
'file_operation',
'tool',
`file_operation#${event.tool_name}`,
{
properties: {
snapshots: JSON.stringify({
tool_name: event.tool_name,
operation: event.operation,
lines: event.lines,
mimetype: event.mimetype,
extension: event.extension,
programming_language: event.programming_language,
},
snapshots: event.diff_stat
? JSON.stringify({ diff_stat: event.diff_stat })
: undefined,
}),
},
);
@@ -465,6 +509,36 @@ export class QwenLogger {
this.flushIfNeeded();
}
logSubagentExecutionEvent(event: SubagentExecutionEvent): void {
const rumEvent = this.createActionEvent('tool', 'subagent_execution', {
snapshots: JSON.stringify({
subagent_name: event.subagent_name,
status: event.status,
terminate_reason: event.terminate_reason,
execution_summary: event.execution_summary,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logToolOutputTruncatedEvent(event: ToolOutputTruncatedEvent): void {
const rumEvent = this.createActionEvent('tool', 'tool_output_truncated', {
snapshots: JSON.stringify({
tool_name: event.tool_name,
original_content_length: event.original_content_length,
truncated_content_length: event.truncated_content_length,
threshold: event.threshold,
lines: event.lines,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// api events
logApiRequestEvent(event: ApiRequestEvent): void {
const rumEvent = this.createResourceEvent('api', 'api_request', {
properties: {
@@ -482,7 +556,6 @@ export class QwenLogger {
status_code: event.status_code?.toString() ?? '',
duration: event.duration_ms,
success: 1,
message: event.error,
trace_id: event.response_id,
properties: {
auth_type: event.auth_type,
@@ -502,6 +575,19 @@ export class QwenLogger {
this.flushIfNeeded();
}
logApiCancelEvent(event: ApiCancelEvent): void {
const rumEvent = this.createActionEvent('api', 'api_cancel', {
properties: {
model: event.model,
prompt_id: event.prompt_id,
auth_type: event.auth_type,
},
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logApiErrorEvent(event: ApiErrorEvent): void {
const rumEvent = this.createResourceEvent('api', 'api_error', {
status_code: event.status_code?.toString() ?? '',
@@ -523,129 +609,7 @@ export class QwenLogger {
this.flushIfNeeded();
}
logFlashFallbackEvent(event: FlashFallbackEvent): void {
const rumEvent = this.createActionEvent('fallback', 'flash_fallback', {
properties: {
auth_type: event.auth_type,
},
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logLoopDetectedEvent(event: LoopDetectedEvent): void {
const rumEvent = this.createExceptionEvent('error', 'loop_detected', {
subtype: 'loop_detected',
properties: {
prompt_id: event.prompt_id,
},
snapshots: JSON.stringify({
loop_type: event.loop_type,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logNextSpeakerCheck(event: NextSpeakerCheckEvent): void {
const rumEvent = this.createActionEvent('check', 'next_speaker_check', {
properties: {
prompt_id: event.prompt_id,
},
snapshots: JSON.stringify({
finish_reason: event.finish_reason,
result: event.result,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logSlashCommandEvent(event: SlashCommandEvent): void {
const rumEvent = this.createActionEvent('command', 'slash_command', {
snapshots: JSON.stringify({
command: event.command,
subcommand: event.subcommand,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logMalformedJsonResponseEvent(event: MalformedJsonResponseEvent): void {
const rumEvent = this.createExceptionEvent(
'error',
'malformed_json_response',
{
subtype: 'malformed_json_response',
properties: {
model: event.model,
},
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logIdeConnectionEvent(event: IdeConnectionEvent): void {
const rumEvent = this.createActionEvent('connection', 'ide_connection', {
snapshots: JSON.stringify({ connection_type: event.connection_type }),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logConversationFinishedEvent(event: ConversationFinishedEvent): void {
const rumEvent = this.createActionEvent(
'conversation',
'conversation_finished',
{
snapshots: JSON.stringify({
approval_mode: event.approvalMode,
turn_count: event.turnCount,
}),
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logKittySequenceOverflowEvent(event: KittySequenceOverflowEvent): void {
const rumEvent = this.createExceptionEvent(
'overflow',
'kitty_sequence_overflow',
{
subtype: 'kitty_sequence_overflow',
snapshots: JSON.stringify({
sequence_length: event.sequence_length,
truncated_sequence: event.truncated_sequence,
}),
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logChatCompressionEvent(event: ChatCompressionEvent): void {
const rumEvent = this.createActionEvent('compression', 'chat_compression', {
snapshots: JSON.stringify({
tokens_before: event.tokens_before,
tokens_after: event.tokens_after,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// error events
logInvalidChunkEvent(event: InvalidChunkEvent): void {
const rumEvent = this.createExceptionEvent('error', 'invalid_chunk', {
subtype: 'invalid_chunk',
@@ -656,19 +620,6 @@ export class QwenLogger {
this.flushIfNeeded();
}
logContentRetryEvent(event: ContentRetryEvent): void {
const rumEvent = this.createActionEvent('retry', 'content_retry', {
snapshots: JSON.stringify({
attempt_number: event.attempt_number,
error_type: event.error_type,
retry_delay_ms: event.retry_delay_ms,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logContentRetryFailureEvent(event: ContentRetryFailureEvent): void {
const rumEvent = this.createExceptionEvent(
'error',
@@ -688,13 +639,30 @@ export class QwenLogger {
this.flushIfNeeded();
}
logSubagentExecutionEvent(event: SubagentExecutionEvent): void {
const rumEvent = this.createActionEvent('subagent', 'subagent_execution', {
logMalformedJsonResponseEvent(event: MalformedJsonResponseEvent): void {
const rumEvent = this.createExceptionEvent(
'error',
'malformed_json_response',
{
subtype: 'malformed_json_response',
properties: {
model: event.model,
},
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logLoopDetectedEvent(event: LoopDetectedEvent): void {
const rumEvent = this.createExceptionEvent('error', 'loop_detected', {
subtype: 'loop_detected',
properties: {
prompt_id: event.prompt_id,
},
snapshots: JSON.stringify({
subagent_name: event.subagent_name,
status: event.status,
terminate_reason: event.terminate_reason,
execution_summary: event.execution_summary,
loop_type: event.loop_type,
}),
});
@@ -702,16 +670,156 @@ export class QwenLogger {
this.flushIfNeeded();
}
logEndSessionEvent(_event: EndSessionEvent): void {
const applicationEvent = this.createViewEvent('session', 'session_end', {});
logKittySequenceOverflowEvent(event: KittySequenceOverflowEvent): void {
const rumEvent = this.createExceptionEvent(
'overflow',
'kitty_sequence_overflow',
{
subtype: 'kitty_sequence_overflow',
snapshots: JSON.stringify({
sequence_length: event.sequence_length,
truncated_sequence: event.truncated_sequence,
}),
},
);
// Flush immediately on session end.
this.enqueueLogEvent(applicationEvent);
this.flushToRum().catch((error: unknown) => {
if (this.config?.getDebugMode()) {
console.debug('Error flushing to RUM:', error);
}
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// ide events
logIdeConnectionEvent(event: IdeConnectionEvent): void {
const rumEvent = this.createActionEvent('ide', 'ide_connection', {
snapshots: JSON.stringify({ connection_type: event.connection_type }),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// extension events
logExtensionInstallEvent(event: ExtensionInstallEvent): void {
const rumEvent = this.createActionEvent('extension', 'extension_install', {
snapshots: JSON.stringify({
extension_name: event.extension_name,
extension_version: event.extension_version,
extension_source: event.extension_source,
status: event.status,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logExtensionUninstallEvent(event: ExtensionUninstallEvent): void {
const rumEvent = this.createActionEvent(
'extension',
'extension_uninstall',
{
snapshots: JSON.stringify({
extension_name: event.extension_name,
status: event.status,
}),
},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logExtensionEnableEvent(event: ExtensionEnableEvent): void {
const rumEvent = this.createActionEvent('extension', 'extension_enable', {
snapshots: JSON.stringify({
extension_name: event.extension_name,
setting_scope: event.setting_scope,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logExtensionDisableEvent(event: ExtensionDisableEvent): void {
const rumEvent = this.createActionEvent('extension', 'extension_disable', {
snapshots: JSON.stringify({
extension_name: event.extension_name,
setting_scope: event.setting_scope,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
// misc events
logFlashFallbackEvent(event: FlashFallbackEvent): void {
const rumEvent = this.createActionEvent('misc', 'flash_fallback', {
properties: {
auth_type: event.auth_type,
},
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logRipgrepFallbackEvent(): void {
const rumEvent = this.createActionEvent('misc', 'ripgrep_fallback', {});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logLoopDetectionDisabledEvent(): void {
const rumEvent = this.createActionEvent(
'misc',
'loop_detection_disabled',
{},
);
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logNextSpeakerCheck(event: NextSpeakerCheckEvent): void {
const rumEvent = this.createActionEvent('misc', 'next_speaker_check', {
properties: {
prompt_id: event.prompt_id,
},
snapshots: JSON.stringify({
finish_reason: event.finish_reason,
result: event.result,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logChatCompressionEvent(event: ChatCompressionEvent): void {
const rumEvent = this.createActionEvent('misc', 'chat_compression', {
snapshots: JSON.stringify({
tokens_before: event.tokens_before,
tokens_after: event.tokens_after,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
logContentRetryEvent(event: ContentRetryEvent): void {
const rumEvent = this.createActionEvent('misc', 'content_retry', {
snapshots: JSON.stringify({
attempt_number: event.attempt_number,
error_type: event.error_type,
retry_delay_ms: event.retry_delay_ms,
}),
});
this.enqueueLogEvent(rumEvent);
this.flushIfNeeded();
}
getProxyAgent() {

44
packages/core/src/telemetry/sdk.test.ts
View File

@@ -14,6 +14,10 @@ import { OTLPTraceExporter as OTLPTraceExporterHttp } from '@opentelemetry/expor
import { OTLPLogExporter as OTLPLogExporterHttp } from '@opentelemetry/exporter-logs-otlp-http';
import { OTLPMetricExporter as OTLPMetricExporterHttp } from '@opentelemetry/exporter-metrics-otlp-http';
import { NodeSDK } from '@opentelemetry/sdk-node';
import { TelemetryTarget } from './index.js';
import * as os from 'node:os';
import * as path from 'node:path';
vi.mock('@opentelemetry/exporter-trace-otlp-grpc');
vi.mock('@opentelemetry/exporter-logs-otlp-grpc');
@@ -22,6 +26,7 @@ vi.mock('@opentelemetry/exporter-trace-otlp-http');
vi.mock('@opentelemetry/exporter-logs-otlp-http');
vi.mock('@opentelemetry/exporter-metrics-otlp-http');
vi.mock('@opentelemetry/sdk-node');
vi.mock('./gcp-exporters.js');
describe('Telemetry SDK', () => {
let mockConfig: Config;
@@ -32,6 +37,8 @@ describe('Telemetry SDK', () => {
getTelemetryEnabled: () => true,
getTelemetryOtlpEndpoint: () => 'http://localhost:4317',
getTelemetryOtlpProtocol: () => 'grpc',
getTelemetryTarget: () => 'local',
getTelemetryUseCollector: () => false,
getTelemetryOutfile: () => undefined,
getDebugMode: () => false,
getSessionId: () => 'test-session',
@@ -101,4 +108,41 @@ describe('Telemetry SDK', () => {
expect.objectContaining({ url: 'https://my-collector.com/' }),
);
});
it('should use OTLP exporters when target is gcp but useCollector is true', () => {
vi.spyOn(mockConfig, 'getTelemetryTarget').mockReturnValue(
TelemetryTarget.GCP,
);
vi.spyOn(mockConfig, 'getTelemetryUseCollector').mockReturnValue(true);
initializeTelemetry(mockConfig);
expect(OTLPTraceExporter).toHaveBeenCalledWith({
url: 'http://localhost:4317',
compression: 'gzip',
});
expect(OTLPLogExporter).toHaveBeenCalledWith({
url: 'http://localhost:4317',
compression: 'gzip',
});
expect(OTLPMetricExporter).toHaveBeenCalledWith({
url: 'http://localhost:4317',
compression: 'gzip',
});
});
it('should not use OTLP exporters when telemetryOutfile is set', () => {
vi.spyOn(mockConfig, 'getTelemetryOutfile').mockReturnValue(
path.join(os.tmpdir(), 'test.log'),
);
initializeTelemetry(mockConfig);
expect(OTLPTraceExporter).not.toHaveBeenCalled();
expect(OTLPLogExporter).not.toHaveBeenCalled();
expect(OTLPMetricExporter).not.toHaveBeenCalled();
expect(OTLPTraceExporterHttp).not.toHaveBeenCalled();
expect(OTLPLogExporterHttp).not.toHaveBeenCalled();
expect(OTLPMetricExporterHttp).not.toHaveBeenCalled();
expect(NodeSDK.prototype.start).toHaveBeenCalled();
});
});

5
packages/core/src/telemetry/sdk.ts
View File

@@ -86,8 +86,8 @@ export function initializeTelemetry(config: Config): void {
const otlpEndpoint = config.getTelemetryOtlpEndpoint();
const otlpProtocol = config.getTelemetryOtlpProtocol();
const parsedEndpoint = parseOtlpEndpoint(otlpEndpoint, otlpProtocol);
const useOtlp = !!parsedEndpoint;
const telemetryOutfile = config.getTelemetryOutfile();
const useOtlp = !!parsedEndpoint && !telemetryOutfile;
let spanExporter:
| OTLPTraceExporter
@@ -174,6 +174,9 @@ export function initializeTelemetry(config: Config): void {
process.on('SIGINT', () => {
shutdownTelemetry(config);
});
process.on('exit', () => {
shutdownTelemetry(config);
});
}
export async function shutdownTelemetry(config: Config): Promise<void> {

179
packages/core/src/telemetry/types.ts
View File

@@ -9,7 +9,7 @@ import type { Config } from '../config/config.js';
import type { ApprovalMode } from '../config/config.js';
import type { CompletedToolCall } from '../core/coreToolScheduler.js';
import { DiscoveredMCPTool } from '../tools/mcp-tool.js';
import type { DiffStat, FileDiff } from '../tools/tools.js';
import type { FileDiff } from '../tools/tools.js';
import { AuthType } from '../core/contentGenerator.js';
import {
getDecisionFromOutcome,
@@ -18,6 +18,7 @@ import {
import type { FileOperation } from './metrics.js';
export { ToolCallDecision };
import type { ToolRegistry } from '../tools/tool-registry.js';
import type { OutputFormat } from '../output/types.js';
export interface BaseTelemetryEvent {
'event.name': string;
@@ -45,6 +46,7 @@ export class StartSessionEvent implements BaseTelemetryEvent {
mcp_servers_count: number;
mcp_tools_count?: number;
mcp_tools?: string;
output_format: OutputFormat;
constructor(config: Config, toolRegistry?: ToolRegistry) {
const generatorConfig = config.getContentGeneratorConfig();
@@ -74,6 +76,7 @@ export class StartSessionEvent implements BaseTelemetryEvent {
this.file_filtering_respect_git_ignore =
config.getFileFilteringRespectGitIgnore();
this.mcp_servers_count = mcpServers ? Object.keys(mcpServers).length : 0;
this.output_format = config.getOutputFormat();
if (toolRegistry) {
const mcpTools = toolRegistry
.getAllTools()
@@ -135,6 +138,8 @@ export class ToolCallEvent implements BaseTelemetryEvent {
prompt_id: string;
response_id?: string;
tool_type: 'native' | 'mcp';
content_length?: number;
mcp_server_name?: string;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
metadata?: { [key: string]: any };
@@ -152,11 +157,17 @@ export class ToolCallEvent implements BaseTelemetryEvent {
this.error = call.response.error?.message;
this.error_type = call.response.errorType;
this.prompt_id = call.request.prompt_id;
this.content_length = call.response.contentLength;
if (
typeof call.tool !== 'undefined' &&
call.tool instanceof DiscoveredMCPTool
) {
this.tool_type = 'mcp';
this.mcp_server_name = call.tool.serverName;
} else {
this.tool_type = 'native';
}
this.response_id = call.request.response_id;
this.tool_type =
typeof call.tool !== 'undefined' && call.tool instanceof DiscoveredMCPTool
? 'mcp'
: 'native';
if (
call.status === 'success' &&
@@ -167,10 +178,14 @@ export class ToolCallEvent implements BaseTelemetryEvent {
const diffStat = (call.response.resultDisplay as FileDiff).diffStat;
if (diffStat) {
this.metadata = {
ai_added_lines: diffStat.ai_added_lines,
ai_removed_lines: diffStat.ai_removed_lines,
model_added_lines: diffStat.model_added_lines,
model_removed_lines: diffStat.model_removed_lines,
model_added_chars: diffStat.model_added_chars,
model_removed_chars: diffStat.model_removed_chars,
user_added_lines: diffStat.user_added_lines,
user_removed_lines: diffStat.user_removed_lines,
user_added_chars: diffStat.user_added_chars,
user_removed_chars: diffStat.user_removed_chars,
};
}
}
@@ -251,7 +266,6 @@ export class ApiResponseEvent implements BaseTelemetryEvent {
model: string;
status_code?: number | string;
duration_ms: number;
error?: string;
input_token_count: number;
output_token_count: number;
cached_content_token_count: number;
@@ -270,7 +284,6 @@ export class ApiResponseEvent implements BaseTelemetryEvent {
auth_type?: string,
usage_data?: GenerateContentResponseUsageMetadata,
response_text?: string,
error?: string,
) {
this['event.name'] = 'api_response';
this['event.timestamp'] = new Date().toISOString();
@@ -285,7 +298,6 @@ export class ApiResponseEvent implements BaseTelemetryEvent {
this.tool_token_count = usage_data?.toolUsePromptTokenCount ?? 0;
this.total_token_count = usage_data?.totalTokenCount ?? 0;
this.response_text = response_text;
this.error = error;
this.prompt_id = prompt_id;
this.auth_type = auth_type;
}
@@ -303,6 +315,16 @@ export class FlashFallbackEvent implements BaseTelemetryEvent {
}
}
export class RipgrepFallbackEvent implements BaseTelemetryEvent {
'event.name': 'ripgrep_fallback';
'event.timestamp': string;
constructor(public error?: string) {
this['event.name'] = 'ripgrep_fallback';
this['event.timestamp'] = new Date().toISOString();
}
}
export enum LoopType {
CONSECUTIVE_IDENTICAL_TOOL_CALLS = 'consecutive_identical_tool_calls',
CHANTING_IDENTICAL_SENTENCES = 'chanting_identical_sentences',
@@ -323,6 +345,18 @@ export class LoopDetectedEvent implements BaseTelemetryEvent {
}
}
export class LoopDetectionDisabledEvent implements BaseTelemetryEvent {
'event.name': 'loop_detection_disabled';
'event.timestamp': string;
prompt_id: string;
constructor(prompt_id: string) {
this['event.name'] = 'loop_detection_disabled';
this['event.timestamp'] = new Date().toISOString();
this.prompt_id = prompt_id;
}
}
export class NextSpeakerCheckEvent implements BaseTelemetryEvent {
'event.name': 'next_speaker_check';
'event.timestamp': string;
@@ -450,7 +484,6 @@ export class FileOperationEvent implements BaseTelemetryEvent {
lines?: number;
mimetype?: string;
extension?: string;
diff_stat?: DiffStat;
programming_language?: string;
constructor(
@@ -459,7 +492,6 @@ export class FileOperationEvent implements BaseTelemetryEvent {
lines?: number,
mimetype?: string,
extension?: string,
diff_stat?: DiffStat,
programming_language?: string,
) {
this['event.name'] = 'file_operation';
@@ -469,7 +501,6 @@ export class FileOperationEvent implements BaseTelemetryEvent {
this.lines = lines;
this.mimetype = mimetype;
this.extension = extension;
this.diff_stat = diff_stat;
this.programming_language = programming_language;
}
}
@@ -493,17 +524,20 @@ export class ContentRetryEvent implements BaseTelemetryEvent {
attempt_number: number;
error_type: string; // e.g., 'EmptyStreamError'
retry_delay_ms: number;
model: string;
constructor(
attempt_number: number,
error_type: string,
retry_delay_ms: number,
model: string,
) {
this['event.name'] = 'content_retry';
this['event.timestamp'] = new Date().toISOString();
this.attempt_number = attempt_number;
this.error_type = error_type;
this.retry_delay_ms = retry_delay_ms;
this.model = model;
}
}
@@ -513,10 +547,12 @@ export class ContentRetryFailureEvent implements BaseTelemetryEvent {
total_attempts: number;
final_error_type: string;
total_duration_ms?: number; // Optional: total time spent retrying
model: string;
constructor(
total_attempts: number,
final_error_type: string,
model: string,
total_duration_ms?: number,
) {
this['event.name'] = 'content_retry_failure';
@@ -524,6 +560,101 @@ export class ContentRetryFailureEvent implements BaseTelemetryEvent {
this.total_attempts = total_attempts;
this.final_error_type = final_error_type;
this.total_duration_ms = total_duration_ms;
this.model = model;
}
}
export class ExtensionInstallEvent implements BaseTelemetryEvent {
'event.name': 'extension_install';
'event.timestamp': string;
extension_name: string;
extension_version: string;
extension_source: string;
status: 'success' | 'error';
constructor(
extension_name: string,
extension_version: string,
extension_source: string,
status: 'success' | 'error',
) {
this['event.name'] = 'extension_install';
this['event.timestamp'] = new Date().toISOString();
this.extension_name = extension_name;
this.extension_version = extension_version;
this.extension_source = extension_source;
this.status = status;
}
}
export class ToolOutputTruncatedEvent implements BaseTelemetryEvent {
readonly eventName = 'tool_output_truncated';
readonly 'event.timestamp' = new Date().toISOString();
'event.name': string;
tool_name: string;
original_content_length: number;
truncated_content_length: number;
threshold: number;
lines: number;
prompt_id: string;
constructor(
prompt_id: string,
details: {
toolName: string;
originalContentLength: number;
truncatedContentLength: number;
threshold: number;
lines: number;
},
) {
this['event.name'] = this.eventName;
this.prompt_id = prompt_id;
this.tool_name = details.toolName;
this.original_content_length = details.originalContentLength;
this.truncated_content_length = details.truncatedContentLength;
this.threshold = details.threshold;
this.lines = details.lines;
}
}
export class ExtensionUninstallEvent implements BaseTelemetryEvent {
'event.name': 'extension_uninstall';
'event.timestamp': string;
extension_name: string;
status: 'success' | 'error';
constructor(extension_name: string, status: 'success' | 'error') {
this['event.name'] = 'extension_uninstall';
this['event.timestamp'] = new Date().toISOString();
this.extension_name = extension_name;
this.status = status;
}
}
export class ExtensionEnableEvent implements BaseTelemetryEvent {
'event.name': 'extension_enable';
'event.timestamp': string;
extension_name: string;
setting_scope: string;
constructor(extension_name: string, settingScope: string) {
this['event.name'] = 'extension_enable';
this['event.timestamp'] = new Date().toISOString();
this.extension_name = extension_name;
this.setting_scope = settingScope;
}
}
export class ModelSlashCommandEvent implements BaseTelemetryEvent {
'event.name': 'model_slash_command';
'event.timestamp': string;
model_name: string;
constructor(model_name: string) {
this['event.name'] = 'model_slash_command';
this['event.timestamp'] = new Date().toISOString();
this.model_name = model_name;
}
}
@@ -566,6 +697,7 @@ export type TelemetryEvent =
| ApiResponseEvent
| FlashFallbackEvent
| LoopDetectedEvent
| LoopDetectionDisabledEvent
| NextSpeakerCheckEvent
| KittySequenceOverflowEvent
| MalformedJsonResponseEvent
@@ -576,4 +708,23 @@ export type TelemetryEvent =
| InvalidChunkEvent
| ContentRetryEvent
| ContentRetryFailureEvent
| SubagentExecutionEvent;
| SubagentExecutionEvent
| ExtensionEnableEvent
| ExtensionInstallEvent
| ExtensionUninstallEvent
| ToolOutputTruncatedEvent
| ModelSlashCommandEvent;
export class ExtensionDisableEvent implements BaseTelemetryEvent {
'event.name': 'extension_disable';
'event.timestamp': string;
extension_name: string;
setting_scope: string;
constructor(extension_name: string, settingScope: string) {
this['event.name'] = 'extension_disable';
this['event.timestamp'] = new Date().toISOString();
this.extension_name = extension_name;
this.setting_scope = settingScope;
}
}

34
packages/core/src/telemetry/uiTelemetry.test.ts
View File

@@ -22,7 +22,7 @@ import type {
} from '../core/coreToolScheduler.js';
import { ToolErrorType } from '../tools/tool-error.js';
import { ToolConfirmationOutcome } from '../tools/tools.js';
import { MockTool } from '../test-utils/tools.js';
import { MockTool } from '../test-utils/mock-tool.js';
const createFakeCompletedToolCall = (
name: string,
@@ -38,7 +38,7 @@ const createFakeCompletedToolCall = (
isClientInitiated: false,
prompt_id: 'prompt-id-1',
};
const tool = new MockTool(name);
const tool = new MockTool({ name });
if (success === true) {
return {
@@ -167,7 +167,7 @@ describe('UiTelemetryService', () => {
expect(spy).toHaveBeenCalledOnce();
const { metrics, lastPromptTokenCount } = spy.mock.calls[0][0];
expect(metrics).toBeDefined();
expect(lastPromptTokenCount).toBe(10);
expect(lastPromptTokenCount).toBe(0);
});
describe('API Response Event Processing', () => {
@@ -202,7 +202,7 @@ describe('UiTelemetryService', () => {
tool: 3,
},
});
expect(service.getLastPromptTokenCount()).toBe(10);
expect(service.getLastPromptTokenCount()).toBe(0);
});
it('should aggregate multiple ApiResponseEvents for the same model', () => {
@@ -252,7 +252,7 @@ describe('UiTelemetryService', () => {
tool: 9,
},
});
expect(service.getLastPromptTokenCount()).toBe(15);
expect(service.getLastPromptTokenCount()).toBe(0);
});
it('should handle ApiResponseEvents for different models', () => {
@@ -291,7 +291,7 @@ describe('UiTelemetryService', () => {
expect(metrics.models['gemini-2.5-flash']).toBeDefined();
expect(metrics.models['gemini-2.5-pro'].api.totalRequests).toBe(1);
expect(metrics.models['gemini-2.5-flash'].api.totalRequests).toBe(1);
expect(service.getLastPromptTokenCount()).toBe(100);
expect(service.getLastPromptTokenCount()).toBe(0);
});
});
@@ -602,10 +602,10 @@ describe('UiTelemetryService', () => {
} as ApiResponseEvent & { 'event.name': typeof EVENT_API_RESPONSE };
service.addEvent(event);
expect(service.getLastPromptTokenCount()).toBe(100);
expect(service.getLastPromptTokenCount()).toBe(0);
// Now reset the token count
service.resetLastPromptTokenCount();
service.setLastPromptTokenCount(0);
expect(service.getLastPromptTokenCount()).toBe(0);
});
@@ -629,7 +629,7 @@ describe('UiTelemetryService', () => {
service.addEvent(event);
spy.mockClear(); // Clear the spy to focus on the reset call
service.resetLastPromptTokenCount();
service.setLastPromptTokenCount(0);
expect(spy).toHaveBeenCalledOnce();
const { metrics, lastPromptTokenCount } = spy.mock.calls[0][0];
@@ -655,7 +655,7 @@ describe('UiTelemetryService', () => {
const metricsBefore = service.getMetrics();
service.resetLastPromptTokenCount();
service.setLastPromptTokenCount(0);
const metricsAfter = service.getMetrics();
@@ -684,15 +684,15 @@ describe('UiTelemetryService', () => {
} as ApiResponseEvent & { 'event.name': typeof EVENT_API_RESPONSE };
service.addEvent(event);
expect(service.getLastPromptTokenCount()).toBe(100);
expect(service.getLastPromptTokenCount()).toBe(0);
// Reset once
service.resetLastPromptTokenCount();
service.setLastPromptTokenCount(0);
expect(service.getLastPromptTokenCount()).toBe(0);
// Reset again - should still be 0 and still emit event
spy.mockClear();
service.resetLastPromptTokenCount();
service.setLastPromptTokenCount(0);
expect(service.getLastPromptTokenCount()).toBe(0);
expect(spy).toHaveBeenCalledOnce();
});
@@ -733,8 +733,8 @@ describe('UiTelemetryService', () => {
...structuredClone(new ToolCallEvent(toolCall)),
'event.name': EVENT_TOOL_CALL,
metadata: {
ai_added_lines: 10,
ai_removed_lines: 5,
model_added_lines: 10,
model_removed_lines: 5,
},
} as ToolCallEvent & { 'event.name': typeof EVENT_TOOL_CALL };
@@ -751,8 +751,8 @@ describe('UiTelemetryService', () => {
...structuredClone(new ToolCallEvent(toolCall)),
'event.name': EVENT_TOOL_CALL,
metadata: {
ai_added_lines: null,
ai_removed_lines: undefined,
model_added_lines: null,
model_removed_lines: undefined,
},
} as ToolCallEvent & { 'event.name': typeof EVENT_TOOL_CALL };

14
packages/core/src/telemetry/uiTelemetry.ts
View File

@@ -144,8 +144,8 @@ export class UiTelemetryService extends EventEmitter {
return this.#lastPromptTokenCount;
}
resetLastPromptTokenCount(): void {
this.#lastPromptTokenCount = 0;
setLastPromptTokenCount(lastPromptTokenCount: number): void {
this.#lastPromptTokenCount = lastPromptTokenCount;
this.emit('update', {
metrics: this.#metrics,
lastPromptTokenCount: this.#lastPromptTokenCount,
@@ -171,8 +171,6 @@ export class UiTelemetryService extends EventEmitter {
modelMetrics.tokens.cached += event.cached_content_token_count;
modelMetrics.tokens.thoughts += event.thoughts_token_count;
modelMetrics.tokens.tool += event.tool_token_count;
this.#lastPromptTokenCount = event.input_token_count;
}
private processApiError(event: ApiErrorEvent) {
@@ -224,11 +222,11 @@ export class UiTelemetryService extends EventEmitter {
// Aggregate line count data from metadata
if (event.metadata) {
if (event.metadata['ai_added_lines'] !== undefined) {
files.totalLinesAdded += event.metadata['ai_added_lines'];
if (event.metadata['model_added_lines'] !== undefined) {
files.totalLinesAdded += event.metadata['model_added_lines'];
}
if (event.metadata['ai_removed_lines'] !== undefined) {
files.totalLinesRemoved += event.metadata['ai_removed_lines'];
if (event.metadata['model_removed_lines'] !== undefined) {
files.totalLinesRemoved += event.metadata['model_removed_lines'];
}
}
}