From e7bcbcda2090ca780e407b19937cac5cee406436 Mon Sep 17 00:00:00 2001 From: Automaker Date: Thu, 30 Apr 2026 16:25:35 -0700 Subject: [PATCH 1/2] chore(telemetry): rebrand qwen-code identifiers to proto-cli MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Aligns telemetry / public-facing identifiers with the actual product name. Verified against the Langfuse instance: new spans land with service.name=proto-cli on scope=proto.openai-pipeline; existing proto.* tracers (proto.llm, proto.turn, proto.tools, proto.harness, etc.) were already correct. Changes: - SERVICE_NAME: qwen-code → proto-cli (resource attribute, the marquee label in Langfuse's service column) - All EVENT_* constants: qwen-code.* → proto.* (matches the existing proto.harness.* convention already in this file) - pipeline.ts tracer: qwen-code.openai-pipeline → proto.openai-pipeline (one straggler vs. the 9 other proto.* tracers in core/) - types.ts event.name literals (PromptSuggestion, Speculation): qwen-code.* → proto.* - acpAgent.ts agentInfo.name: qwen-code → proto-cli (visible to ACP clients like Zed when listing agents) - marketplace.ts User-Agent: qwen-code → proto-cli (extension fetch identifier sent to api.github.com / raw.githubusercontent.com) Out of scope (deliberately): - packages/core/src/telemetry/qwen-logger/* — separate analytics ping to gb4w8c3ygj-default-sea.rum.aliyuncs.com (Alibaba RUM, the upstream Qwen team's endpoint). Should be disabled rather than rebranded; tracking separately. - DEFAULT_SERVICE_NAME='qwen-code-oauth' in mcp/token-storage — renaming would orphan existing keychain entries. - Misc qwen-code-* file paths, tmp dir names, sandbox image tag, test fixtures — not telemetry / not user-visible labels. Co-Authored-By: Claude Opus 4.7 (1M context) --- packages/cli/src/acp-integration/acpAgent.ts | 2 +- .../core/openaiContentGenerator/pipeline.ts | 2 +- packages/core/src/extension/marketplace.ts | 4 +- packages/core/src/telemetry/constants.ts | 82 +++++++++---------- packages/core/src/telemetry/types.ts | 8 +- 5 files changed, 48 insertions(+), 50 deletions(-) diff --git a/packages/cli/src/acp-integration/acpAgent.ts b/packages/cli/src/acp-integration/acpAgent.ts index 2eb1d8580..8fceaafe3 100644 --- a/packages/cli/src/acp-integration/acpAgent.ts +++ b/packages/cli/src/acp-integration/acpAgent.ts @@ -159,7 +159,7 @@ class QwenAgent implements Agent { return { protocolVersion: PROTOCOL_VERSION, agentInfo: { - name: 'qwen-code', + name: 'proto-cli', title: 'proto', version, }, diff --git a/packages/core/src/core/openaiContentGenerator/pipeline.ts b/packages/core/src/core/openaiContentGenerator/pipeline.ts index 84715e48f..732b34435 100644 --- a/packages/core/src/core/openaiContentGenerator/pipeline.ts +++ b/packages/core/src/core/openaiContentGenerator/pipeline.ts @@ -18,7 +18,7 @@ import type { ErrorHandler, RequestContext } from './errorHandler.js'; import { createDebugLogger } from '../../utils/debugLogger.js'; const debugLogger = createDebugLogger('OPENAI_PIPELINE'); -const tracer = trace.getTracer('qwen-code.openai-pipeline', '1.0.0'); +const tracer = trace.getTracer('proto.openai-pipeline', '1.0.0'); /** * Error thrown when the API returns an error embedded as stream content diff --git a/packages/core/src/extension/marketplace.ts b/packages/core/src/extension/marketplace.ts index 4ec7b8298..ee88bdd25 100644 --- a/packages/core/src/extension/marketplace.ts +++ b/packages/core/src/extension/marketplace.ts @@ -156,7 +156,7 @@ async function fetchGitHubMarketplaceConfig( // Primary: GitHub API (works for private repos, but has rate limits) const apiUrl = `https://api.github.com/repos/${owner}/${repo}/contents/.claude-plugin/marketplace.json`; const apiHeaders: Record = { - 'User-Agent': 'qwen-code', + 'User-Agent': 'proto-cli', Accept: 'application/vnd.github.v3.raw', }; if (token) { @@ -169,7 +169,7 @@ async function fetchGitHubMarketplaceConfig( if (!content) { const rawUrl = `https://raw.githubusercontent.com/${owner}/${repo}/HEAD/.claude-plugin/marketplace.json`; const rawHeaders: Record = { - 'User-Agent': 'qwen-code', + 'User-Agent': 'proto-cli', }; content = await fetchUrl(rawUrl, rawHeaders); } diff --git a/packages/core/src/telemetry/constants.ts b/packages/core/src/telemetry/constants.ts index 0231df232..237f23e8b 100644 --- a/packages/core/src/telemetry/constants.ts +++ b/packages/core/src/telemetry/constants.ts @@ -4,49 +4,47 @@ * SPDX-License-Identifier: Apache-2.0 */ -export const SERVICE_NAME = 'qwen-code'; +export const SERVICE_NAME = 'proto-cli'; -export const EVENT_USER_PROMPT = 'qwen-code.user_prompt'; -export const EVENT_USER_RETRY = 'qwen-code.user_retry'; -export const EVENT_TOOL_CALL = 'qwen-code.tool_call'; -export const EVENT_API_REQUEST = 'qwen-code.api_request'; -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_EXTENSION_UPDATE = 'qwen-code.extension_update'; -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'; -export const EVENT_CHAT_COMPRESSION = 'qwen-code.chat_compression'; -export const EVENT_INVALID_CHUNK = 'qwen-code.chat.invalid_chunk'; -export const EVENT_CONTENT_RETRY = 'qwen-code.chat.content_retry'; -export const EVENT_CONTENT_RETRY_FAILURE = - 'qwen-code.chat.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 EVENT_SKILL_LAUNCH = 'qwen-code.skill_launch'; -export const EVENT_AUTH = 'qwen-code.auth'; -export const EVENT_USER_FEEDBACK = 'qwen-code.user_feedback'; +export const EVENT_USER_PROMPT = 'proto.user_prompt'; +export const EVENT_USER_RETRY = 'proto.user_retry'; +export const EVENT_TOOL_CALL = 'proto.tool_call'; +export const EVENT_API_REQUEST = 'proto.api_request'; +export const EVENT_API_ERROR = 'proto.api_error'; +export const EVENT_API_CANCEL = 'proto.api_cancel'; +export const EVENT_API_RESPONSE = 'proto.api_response'; +export const EVENT_CLI_CONFIG = 'proto.config'; +export const EVENT_EXTENSION_DISABLE = 'proto.extension_disable'; +export const EVENT_EXTENSION_ENABLE = 'proto.extension_enable'; +export const EVENT_EXTENSION_INSTALL = 'proto.extension_install'; +export const EVENT_EXTENSION_UNINSTALL = 'proto.extension_uninstall'; +export const EVENT_EXTENSION_UPDATE = 'proto.extension_update'; +export const EVENT_FLASH_FALLBACK = 'proto.flash_fallback'; +export const EVENT_RIPGREP_FALLBACK = 'proto.ripgrep_fallback'; +export const EVENT_NEXT_SPEAKER_CHECK = 'proto.next_speaker_check'; +export const EVENT_SLASH_COMMAND = 'proto.slash_command'; +export const EVENT_IDE_CONNECTION = 'proto.ide_connection'; +export const EVENT_CHAT_COMPRESSION = 'proto.chat_compression'; +export const EVENT_INVALID_CHUNK = 'proto.chat.invalid_chunk'; +export const EVENT_CONTENT_RETRY = 'proto.chat.content_retry'; +export const EVENT_CONTENT_RETRY_FAILURE = 'proto.chat.content_retry_failure'; +export const EVENT_CONVERSATION_FINISHED = 'proto.conversation_finished'; +export const EVENT_MALFORMED_JSON_RESPONSE = 'proto.malformed_json_response'; +export const EVENT_FILE_OPERATION = 'proto.file_operation'; +export const EVENT_MODEL_SLASH_COMMAND = 'proto.slash_command.model'; +export const EVENT_SUBAGENT_EXECUTION = 'proto.subagent_execution'; +export const EVENT_SKILL_LAUNCH = 'proto.skill_launch'; +export const EVENT_AUTH = 'proto.auth'; +export const EVENT_USER_FEEDBACK = 'proto.user_feedback'; // Prompt Suggestion Events -export const EVENT_PROMPT_SUGGESTION = 'qwen-code.prompt_suggestion'; -export const EVENT_SPECULATION = 'qwen-code.speculation'; +export const EVENT_PROMPT_SUGGESTION = 'proto.prompt_suggestion'; +export const EVENT_SPECULATION = 'proto.speculation'; // Arena Events -export const EVENT_ARENA_SESSION_STARTED = 'qwen-code.arena_session_started'; -export const EVENT_ARENA_AGENT_COMPLETED = 'qwen-code.arena_agent_completed'; -export const EVENT_ARENA_SESSION_ENDED = 'qwen-code.arena_session_ended'; +export const EVENT_ARENA_SESSION_STARTED = 'proto.arena_session_started'; +export const EVENT_ARENA_AGENT_COMPLETED = 'proto.arena_agent_completed'; +export const EVENT_ARENA_SESSION_ENDED = 'proto.arena_session_ended'; // Harness Events — captured for Langfuse fine-tuning datasets export const EVENT_HARNESS_DOOM_LOOP = 'proto.harness.doom_loop'; @@ -59,7 +57,7 @@ export const EVENT_HARNESS_SPRINT_CONTRACT = 'proto.harness.sprint_contract'; export const EVENT_HARNESS_REMINDER = 'proto.harness.reminder'; // 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'; +export const EVENT_STARTUP_PERFORMANCE = 'proto.startup.performance'; +export const EVENT_MEMORY_USAGE = 'proto.memory.usage'; +export const EVENT_PERFORMANCE_BASELINE = 'proto.performance.baseline'; +export const EVENT_PERFORMANCE_REGRESSION = 'proto.performance.regression'; diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index 575e4c1b1..f5a62c38d 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -1064,7 +1064,7 @@ export class ExtensionDisableEvent implements BaseTelemetryEvent { } export class PromptSuggestionEvent implements BaseTelemetryEvent { - 'event.name': 'qwen-code.prompt_suggestion'; + 'event.name': 'proto.prompt_suggestion'; 'event.timestamp': string; outcome: 'accepted' | 'ignored' | 'suppressed'; prompt_id?: string; @@ -1089,7 +1089,7 @@ export class PromptSuggestionEvent implements BaseTelemetryEvent { was_focused_when_shown?: boolean; reason?: string; }) { - this['event.name'] = 'qwen-code.prompt_suggestion'; + this['event.name'] = 'proto.prompt_suggestion'; this['event.timestamp'] = new Date().toISOString(); this.outcome = params.outcome; this.prompt_id = params.prompt_id ?? 'user_intent'; @@ -1105,7 +1105,7 @@ export class PromptSuggestionEvent implements BaseTelemetryEvent { } export class SpeculationEvent implements BaseTelemetryEvent { - 'event.name': 'qwen-code.speculation'; + 'event.name': 'proto.speculation'; 'event.timestamp': string; outcome: 'accepted' | 'aborted' | 'failed'; turns_used: number; @@ -1124,7 +1124,7 @@ export class SpeculationEvent implements BaseTelemetryEvent { boundary_type?: string; had_pipelined_suggestion: boolean; }) { - this['event.name'] = 'qwen-code.speculation'; + this['event.name'] = 'proto.speculation'; this['event.timestamp'] = new Date().toISOString(); this.outcome = params.outcome; this.turns_used = params.turns_used; From d04e0c72d88743b969c4b27f780117a83d129039 Mon Sep 17 00:00:00 2001 From: Automaker Date: Thu, 30 Apr 2026 16:45:13 -0700 Subject: [PATCH 2/2] chore(telemetry): remove qwen-logger Alibaba RUM ping; keep useful events on Langfuse MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The qwen-logger system shipped usage telemetry to a fixed Alibaba RUM endpoint (gb4w8c3ygj-default-sea.rum.aliyuncs.com) — the upstream Qwen Code team's analytics pipeline. We don't operate that endpoint, the data isn't visible to us, and it labelled traffic as qwen-code-cli / qwen-code@${version}. Confirmed unused on our deployment; nuking. What's removed: - packages/core/src/telemetry/qwen-logger/ (entire directory: logger, event-types, tests) - packages/core/src/telemetry/integration.test.circular.ts (was a qwen-logger-specific circular-reference proxy-agent test, no longer applicable) - ~30 QwenLogger.getInstance(config)?.logXxxEvent(event) callsites in loggers.ts - QwenLogger exports from telemetry/index.ts and core/index.ts - QwenLogger spies and assertions in config.test.ts and the describe('logHookCall', ...) block in loggers.test.ts that was exclusively QwenLogger-shaped What's kept and rerouted to OTel/Langfuse: - HookCallEvent type and the logHookCall function — hook execution data is genuinely useful telemetry (which hook fired, success, duration, exit code, captured stdout/stderr, error). Now emits a proto.hook_call OTel log record via logs.getLogger(SERVICE_NAME) instead of the Alibaba ping. Existing call site in hookEventHandler.ts:619 still fires per hook execution. - LoopDetectionDisabledEvent likewise: was an empty no-op after the qwen-logger pull; rerouted to a proto.loop_detection_disabled OTel log record so the signal still reaches Langfuse. - New tests in loggers.test.ts assert OTel emission shape for logHookCall (success, error, sdk-not-initialized branches). Renamed (per "all not used" — no existing keychain entries to invalidate): - DEFAULT_SERVICE_NAME 'qwen-code-oauth' → 'proto-cli-oauth' - FORCE_ENCRYPTED_FILE_ENV_VAR 'QWEN_CODE_…' → 'PROTO_CLI_…' - file-token-storage encryption salt prefix and scrypt key seed switched to proto-cli; only invalidates non-existent tokens Verified live: kimi-k2.6 turn through the rebuilt CLI lands a Langfuse trace with service=proto-cli, scope=proto.openai-pipeline, gen_ai.response.thinking present. No outbound traffic to aliyuncs.com. Co-Authored-By: Claude Opus 4.7 (1M context) --- packages/core/src/config/config.test.ts | 14 - packages/core/src/core/client.test.ts | 1 - packages/core/src/hooks/hookEventHandler.ts | 6 - packages/core/src/index.ts | 1 - .../mcp/token-storage/file-token-storage.ts | 4 +- packages/core/src/mcp/token-storage/index.ts | 4 +- packages/core/src/telemetry/constants.ts | 2 + packages/core/src/telemetry/index.ts | 1 - .../telemetry/integration.test.circular.ts | 111 -- packages/core/src/telemetry/loggers.test.ts | 274 +---- packages/core/src/telemetry/loggers.ts | 95 +- .../src/telemetry/qwen-logger/event-types.ts | 102 -- .../telemetry/qwen-logger/qwen-logger.test.ts | 829 ------------- .../src/telemetry/qwen-logger/qwen-logger.ts | 1091 ----------------- packages/core/src/telemetry/types.ts | 3 +- 15 files changed, 99 insertions(+), 2439 deletions(-) delete mode 100644 packages/core/src/telemetry/integration.test.circular.ts delete mode 100644 packages/core/src/telemetry/qwen-logger/event-types.ts delete mode 100644 packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts delete mode 100644 packages/core/src/telemetry/qwen-logger/qwen-logger.ts diff --git a/packages/core/src/config/config.test.ts b/packages/core/src/config/config.test.ts index 86998801c..9e8c02fe4 100644 --- a/packages/core/src/config/config.test.ts +++ b/packages/core/src/config/config.test.ts @@ -13,7 +13,6 @@ import { setGeminiMdFilename as mockSetGeminiMdFilename } from '../tools/memoryT import { DEFAULT_TELEMETRY_TARGET, DEFAULT_OTLP_ENDPOINT, - QwenLogger, } from '../telemetry/index.js'; import type { ContentGenerator, @@ -235,9 +234,6 @@ describe('Server Config (config.ts)', () => { beforeEach(() => { // Reset mocks if necessary vi.clearAllMocks(); - vi.spyOn(QwenLogger.prototype, 'logStartSessionEvent').mockImplementation( - async () => undefined, - ); // Setup default mock for resolveContentGeneratorConfigWithSources vi.mocked(resolveContentGeneratorConfigWithSources).mockImplementation( @@ -635,16 +631,6 @@ describe('Server Config (config.ts)', () => { expect(config.getUsageStatisticsEnabled()).toBe(enabled); }, ); - - it('logs the session start event', async () => { - const config = new Config({ - ...baseParams, - usageStatisticsEnabled: true, - }); - await config.initialize(); - - expect(QwenLogger.prototype.logStartSessionEvent).toHaveBeenCalledOnce(); - }); }); describe('Telemetry Settings', () => { diff --git a/packages/core/src/core/client.test.ts b/packages/core/src/core/client.test.ts index 3f96d62ba..bdb516f70 100644 --- a/packages/core/src/core/client.test.ts +++ b/packages/core/src/core/client.test.ts @@ -146,7 +146,6 @@ vi.mock('../telemetry/index.js', async (importOriginal) => { ...actual, uiTelemetryService: mockUiTelemetryService, // We keep the real implementations of logChatCompression, etc. - // but we can spy on QwenLogger if needed }; }); vi.mock('../ide/ideContext.js'); diff --git a/packages/core/src/hooks/hookEventHandler.ts b/packages/core/src/hooks/hookEventHandler.ts index c0778b395..aaf93273d 100644 --- a/packages/core/src/hooks/hookEventHandler.ts +++ b/packages/core/src/hooks/hookEventHandler.ts @@ -652,16 +652,10 @@ export class HookEventHandler { return config.name || 'unknown-hook'; } - /** - * Get hook name from execution result for telemetry - */ private getHookNameFromResult(result: HookExecutionResult): string { return this.getHookName(result.hookConfig); } - /** - * Get hook type from execution result for telemetry - */ private getHookTypeFromResult(result: HookExecutionResult): 'command' { return result.hookConfig.type as 'command'; } diff --git a/packages/core/src/index.ts b/packages/core/src/index.ts index 88273376a..d4cb604e9 100644 --- a/packages/core/src/index.ts +++ b/packages/core/src/index.ts @@ -199,7 +199,6 @@ export type { // Telemetry // ============================================================================ -export { QwenLogger } from './telemetry/qwen-logger/qwen-logger.js'; export * from './telemetry/index.js'; export { logAuth, diff --git a/packages/core/src/mcp/token-storage/file-token-storage.ts b/packages/core/src/mcp/token-storage/file-token-storage.ts index 71c29ac05..4af70268e 100644 --- a/packages/core/src/mcp/token-storage/file-token-storage.ts +++ b/packages/core/src/mcp/token-storage/file-token-storage.ts @@ -23,8 +23,8 @@ export class FileTokenStorage extends BaseTokenStorage { } private deriveEncryptionKey(): Buffer { - const salt = `${os.hostname()}-${os.userInfo().username}-qwen-code`; - return crypto.scryptSync('qwen-code-oauth', salt, 32); + const salt = `${os.hostname()}-${os.userInfo().username}-proto-cli`; + return crypto.scryptSync('proto-cli-oauth', salt, 32); } private encrypt(text: string): string { diff --git a/packages/core/src/mcp/token-storage/index.ts b/packages/core/src/mcp/token-storage/index.ts index 5dde48c6e..4ed83b206 100644 --- a/packages/core/src/mcp/token-storage/index.ts +++ b/packages/core/src/mcp/token-storage/index.ts @@ -9,6 +9,6 @@ export * from './base-token-storage.js'; export * from './file-token-storage.js'; export * from './hybrid-token-storage.js'; -export const DEFAULT_SERVICE_NAME = 'qwen-code-oauth'; +export const DEFAULT_SERVICE_NAME = 'proto-cli-oauth'; export const FORCE_ENCRYPTED_FILE_ENV_VAR = - 'QWEN_CODE_FORCE_ENCRYPTED_FILE_STORAGE'; + 'PROTO_CLI_FORCE_ENCRYPTED_FILE_STORAGE'; diff --git a/packages/core/src/telemetry/constants.ts b/packages/core/src/telemetry/constants.ts index 237f23e8b..83189a253 100644 --- a/packages/core/src/telemetry/constants.ts +++ b/packages/core/src/telemetry/constants.ts @@ -34,6 +34,8 @@ export const EVENT_FILE_OPERATION = 'proto.file_operation'; export const EVENT_MODEL_SLASH_COMMAND = 'proto.slash_command.model'; export const EVENT_SUBAGENT_EXECUTION = 'proto.subagent_execution'; export const EVENT_SKILL_LAUNCH = 'proto.skill_launch'; +export const EVENT_HOOK_CALL = 'proto.hook_call'; +export const EVENT_LOOP_DETECTION_DISABLED = 'proto.loop_detection_disabled'; export const EVENT_AUTH = 'proto.auth'; export const EVENT_USER_FEEDBACK = 'proto.user_feedback'; diff --git a/packages/core/src/telemetry/index.ts b/packages/core/src/telemetry/index.ts index 3395fa9a6..91ea4f939 100644 --- a/packages/core/src/telemetry/index.ts +++ b/packages/core/src/telemetry/index.ts @@ -124,7 +124,6 @@ export { ApiRequestPhase, FileOperation, } from './metrics.js'; -export { QwenLogger } from './qwen-logger/qwen-logger.js'; export { sanitizeHookName } from './sanitize.js'; export { startTurnSpan, diff --git a/packages/core/src/telemetry/integration.test.circular.ts b/packages/core/src/telemetry/integration.test.circular.ts deleted file mode 100644 index a66d50a17..000000000 --- a/packages/core/src/telemetry/integration.test.circular.ts +++ /dev/null @@ -1,111 +0,0 @@ -/** - * @license - * Copyright 2025 Google LLC - * SPDX-License-Identifier: Apache-2.0 - */ - -/** - * Integration test to verify circular reference handling with proxy agents - */ - -import { afterEach, beforeEach, describe, expect, it } from 'vitest'; -import type { Config } from '../config/config.js'; -import type { RumEvent } from './qwen-logger/event-types.js'; -import { QwenLogger } from './qwen-logger/qwen-logger.js'; - -describe('Circular Reference Integration Test', () => { - beforeEach(() => { - // Clear singleton instance before each test - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (QwenLogger as any).instance = undefined; - }); - - afterEach(() => { - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (QwenLogger as any).instance = undefined; - }); - - it('should handle HttpsProxyAgent-like circular references in qwen logging', () => { - // Create a mock config with proxy - const mockConfig = { - getTelemetryEnabled: () => true, - getUsageStatisticsEnabled: () => true, - getSessionId: () => 'test-session', - getModel: () => 'test-model', - getEmbeddingModel: () => 'test-embedding', - getDebugMode: () => false, - getProxy: () => 'http://proxy.example.com:8080', - } as unknown as Config; - - // Simulate the structure that causes the circular reference error - // eslint-disable-next-line @typescript-eslint/no-explicit-any - const proxyAgentLike: any = { - sockets: {}, - options: { proxy: 'http://proxy.example.com:8080' }, - }; - - // eslint-disable-next-line @typescript-eslint/no-explicit-any - const socketLike: any = { - _httpMessage: { - agent: proxyAgentLike, - socket: null, - }, - }; - - socketLike._httpMessage.socket = socketLike; // Create circular reference - proxyAgentLike.sockets['cloudcode-pa.googleapis.com:443'] = [socketLike]; - - // Create an event that would contain this circular structure - const problematicEvent: RumEvent = { - timestamp: Date.now(), - event_type: 'exception', - type: 'error', - name: 'api_error', - error: new Error('Network error'), - function_args: { - filePath: '/test/file.txt', - httpAgent: proxyAgentLike, // This would cause the circular reference - }, - } as RumEvent; - - // Test that QwenLogger can handle this - const logger = QwenLogger.getInstance(mockConfig); - - expect(() => { - // eslint-disable-next-line @typescript-eslint/no-explicit-any - logger?.enqueueLogEvent(problematicEvent as any); - }).not.toThrow(); - }); - - it('should handle event overflow without memory leaks', () => { - const mockConfig = { - getTelemetryEnabled: () => true, - getUsageStatisticsEnabled: () => true, - getSessionId: () => 'test-session', - getDebugMode: () => true, - } as unknown as Config; - - const logger = QwenLogger.getInstance(mockConfig); - - // Add more events than the maximum capacity - for (let i = 0; i < 1100; i++) { - logger?.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: `overflow-test-${i}`, - }); - } - - // Logger should still be functional - expect(logger).toBeDefined(); - expect(() => { - logger?.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'final-test', - }); - }).not.toThrow(); - }); -}); diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index 288e02f03..057941961 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -37,6 +37,7 @@ import { EVENT_EXTENSION_DISABLE, EVENT_EXTENSION_INSTALL, EVENT_EXTENSION_UNINSTALL, + EVENT_HOOK_CALL, } from './constants.js'; import { logApiRequest, @@ -57,7 +58,6 @@ import { logHookCall, } from './loggers.js'; import * as metrics from './metrics.js'; -import { QwenLogger } from './qwen-logger/qwen-logger.js'; import * as sdk from './sdk.js'; import { ToolCallDecision } from './tool-call-decision.js'; import { @@ -109,22 +109,6 @@ describe('loggers', () => { describe('logChatCompression', () => { beforeEach(() => { vi.spyOn(metrics, 'recordChatCompressionMetrics'); - vi.spyOn(QwenLogger.prototype, 'logChatCompressionEvent'); - }); - - it('logs the chat compression event to QwenLogger', () => { - const mockConfig = makeFakeConfig({ sessionId: 'test-session-id' }); - - const event = makeChatCompressionEvent({ - tokens_before: 9001, - tokens_after: 9000, - }); - - logChatCompression(mockConfig, event); - - expect(QwenLogger.prototype.logChatCompressionEvent).toHaveBeenCalledWith( - event, - ); }); it('records the chat compression event to OTEL', () => { @@ -437,9 +421,7 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, } as unknown as Config; - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logRipgrepFallbackEvent'); - }); + beforeEach(() => {}); it('should log ripgrep fallback event', () => { const event = new RipgrepFallbackEvent( @@ -450,8 +432,6 @@ describe('loggers', () => { 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( @@ -468,8 +448,6 @@ describe('loggers', () => { 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( @@ -1013,9 +991,7 @@ describe('loggers', () => { }); describe('logMalformedJsonResponse', () => { - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logMalformedJsonResponseEvent'); - }); + beforeEach(() => {}); it('logs the event to Clearcut and OTEL', () => { const mockConfig = makeFakeConfig({ sessionId: 'test-session-id' }); @@ -1023,10 +999,6 @@ describe('loggers', () => { logMalformedJsonResponse(mockConfig, event); - expect( - QwenLogger.prototype.logMalformedJsonResponseEvent, - ).toHaveBeenCalledWith(event); - expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Malformed JSON response from test-model.', attributes: { @@ -1139,9 +1111,7 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, } as unknown as Config; - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logExtensionInstallEvent'); - }); + beforeEach(() => {}); afterEach(() => { vi.resetAllMocks(); @@ -1157,10 +1127,6 @@ describe('loggers', () => { logExtensionInstallEvent(mockConfig, event); - expect( - QwenLogger.prototype.logExtensionInstallEvent, - ).toHaveBeenCalledWith(event); - expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Installed extension vscode', attributes: { @@ -1182,9 +1148,7 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, } as unknown as Config; - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logExtensionUninstallEvent'); - }); + beforeEach(() => {}); afterEach(() => { vi.resetAllMocks(); @@ -1195,10 +1159,6 @@ describe('loggers', () => { logExtensionUninstall(mockConfig, event); - expect( - QwenLogger.prototype.logExtensionUninstallEvent, - ).toHaveBeenCalledWith(event); - expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Uninstalled extension vscode', attributes: { @@ -1218,9 +1178,7 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, } as unknown as Config; - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logExtensionEnableEvent'); - }); + beforeEach(() => {}); afterEach(() => { vi.resetAllMocks(); @@ -1231,10 +1189,6 @@ describe('loggers', () => { logExtensionEnable(mockConfig, event); - expect(QwenLogger.prototype.logExtensionEnableEvent).toHaveBeenCalledWith( - event, - ); - expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Enabled extension vscode', attributes: { @@ -1254,9 +1208,7 @@ describe('loggers', () => { getUsageStatisticsEnabled: () => true, } as unknown as Config; - beforeEach(() => { - vi.spyOn(QwenLogger.prototype, 'logExtensionDisableEvent'); - }); + beforeEach(() => {}); afterEach(() => { vi.resetAllMocks(); @@ -1267,10 +1219,6 @@ describe('loggers', () => { logExtensionDisable(mockConfig, event); - expect( - QwenLogger.prototype.logExtensionDisableEvent, - ).toHaveBeenCalledWith(event); - expect(mockLogger.emit).toHaveBeenCalledWith({ body: 'Disabled extension vscode', attributes: { @@ -1293,18 +1241,7 @@ describe('loggers', () => { getTelemetryLogPromptsEnabled: () => true, } as unknown as Config; - const mockQwenLogger = { - logHookCallEvent: vi.fn(), - }; - - beforeEach(() => { - vi.spyOn(QwenLogger, 'getInstance').mockReturnValue( - mockQwenLogger as unknown as QwenLogger, - ); - mockQwenLogger.logHookCallEvent.mockClear(); - }); - - it('should log a successful hook call to QwenLogger', () => { + it('emits an OTel log record with the canonical event name and core attributes', () => { const event = new HookCallEvent( 'UserPromptSubmit', 'command', @@ -1321,192 +1258,57 @@ describe('loggers', () => { logHookCall(mockConfig, event); - // Should call QwenLogger - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); + expect(mockLogger.emit).toHaveBeenCalledWith({ + body: expect.stringContaining('Hook call: check-secrets.sh'), + attributes: expect.objectContaining({ + 'session.id': 'test-session-id', + 'event.name': EVENT_HOOK_CALL, + hook_event_name: 'UserPromptSubmit', + hook_type: 'command', + hook_name: 'check-secrets.sh', + duration_ms: 150, + success: true, + exit_code: 0, + stdout: 'stdout message', + stderr: 'stderr message', + }), + }); }); - it('should log a failed hook call with error', () => { + it('includes error.message attribute when the hook failed', () => { const event = new HookCallEvent( 'Stop', 'command', 'cleanup.sh', - { last_assistant_message: 'final message' }, - 200, - false, - undefined, - 1, - 'stdout message', - 'stderr message', - 'Error occurred', - ); - - logHookCall(mockConfig, event); - - // Should call QwenLogger - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - }); - - it('should handle when QwenLogger is not available', () => { - vi.spyOn(QwenLogger, 'getInstance').mockReturnValue(undefined); - - const event = new HookCallEvent( - 'UserPromptSubmit', - 'command', - 'test-hook.sh', - { prompt: 'test' }, - 100, - true, - ); - - // Should not throw when QwenLogger is not available - expect(() => logHookCall(mockConfig, event)).not.toThrow(); - }); - - it('should log hook call with all optional fields', () => { - const event = new HookCallEvent( - 'PreToolUse', - 'command', - 'validator.sh', - { tool_name: 'read_file', path: '/test/file.txt' }, - 250, - true, - { decision: 'allow', reason: 'validated' }, - 0, - 'validation passed', - '', - undefined, - ); - - logHookCall(mockConfig, event); - - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - }); - - it('should log hook call with minimal fields', () => { - const event = new HookCallEvent( - 'SessionStart', - 'command', - 'init.sh', {}, - 10, - true, - ); - - logHookCall(mockConfig, event); - - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - }); - - it('should log hook call with exit code', () => { - const event = new HookCallEvent( - 'PostToolUseFailure', - 'command', - 'error-handler.sh', - { tool_name: 'shell' }, - 50, + 200, false, undefined, 1, '', 'error output', - 'Command failed with exit code 1', - ); - - logHookCall(mockConfig, event); - - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - }); - - it('should log hook call with zero exit code on success', () => { - const event = new HookCallEvent( - 'PostToolUse', - 'command', - 'success-handler.sh', - { tool_name: 'write_file' }, - 100, - true, - { result: 'ok' }, - 0, - 'done', - '', - undefined, - ); - - logHookCall(mockConfig, event); - - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - }); - - it('should log hook call with non-zero exit code on failure', () => { - const event = new HookCallEvent( - 'PostToolUseFailure', - 'command', - 'failure-handler.sh', - { tool_name: 'shell' }, - 75, - false, - undefined, - 127, - '', - 'command not found', - 'Hook command not found', + 'Error occurred', ); logHookCall(mockConfig, event); - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); + const call = mockLogger.emit.mock.calls.at(-1)?.[0] as + | { attributes: Record } + | undefined; + expect(call?.attributes['error.message']).toBe('Error occurred'); + expect(call?.attributes['success']).toBe(false); }); - it('should log all hook event types', () => { - const eventTypes = [ - 'PreToolUse', - 'PostToolUse', - 'PostToolUseFailure', - 'Notification', - 'UserPromptSubmit', - 'SessionStart', - 'SessionEnd', - 'Stop', - 'SubagentStart', - 'SubagentStop', - 'PreCompact', - 'PermissionRequest', - ]; - - for (const eventType of eventTypes) { - mockQwenLogger.logHookCallEvent.mockClear(); - - const event = new HookCallEvent( - eventType, - 'command', - 'test-hook.sh', - {}, - 100, - true, - ); - - logHookCall(mockConfig, event); - - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledWith(event); - } - }); + it('skips emission when telemetry SDK is not initialized', () => { + vi.spyOn(sdk, 'isTelemetrySdkInitialized').mockReturnValue(false); + const callsBefore = mockLogger.emit.mock.calls.length; - it('should pass the exact event object to QwenLogger', () => { - const event = new HookCallEvent( - 'PreToolUse', - 'command', - 'test-hook.sh', - { tool_name: 'read_file' }, - 100, - true, + logHookCall( + mockConfig, + new HookCallEvent('SessionStart', 'command', 'init.sh', {}, 10, true), ); - logHookCall(mockConfig, event); - - // Verify the exact event object is passed - expect(mockQwenLogger.logHookCallEvent).toHaveBeenCalledTimes(1); - const passedEvent = mockQwenLogger.logHookCallEvent.mock.calls[0][0]; - expect(passedEvent).toBe(event); + expect(mockLogger.emit.mock.calls.length).toBe(callsBefore); }); }); }); diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index b7c18c9d3..58691ca0b 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -39,6 +39,8 @@ import { EVENT_INVALID_CHUNK, EVENT_AUTH, EVENT_SKILL_LAUNCH, + EVENT_HOOK_CALL, + EVENT_LOOP_DETECTION_DISABLED, EVENT_EXTENSION_UPDATE, EVENT_USER_FEEDBACK, EVENT_ARENA_SESSION_STARTED, @@ -63,7 +65,6 @@ import { recordArenaAgentCompletedMetrics, recordArenaSessionEndedMetrics, } from './metrics.js'; -import { QwenLogger } from './qwen-logger/qwen-logger.js'; import { isTelemetrySdkInitialized } from './sdk.js'; import type { ApiErrorEvent, @@ -125,7 +126,6 @@ export function logStartSession( config: Config, event: StartSessionEvent, ): void { - QwenLogger.getInstance(config)?.logStartSessionEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -161,7 +161,6 @@ export function logStartSession( } export function logUserPrompt(config: Config, event: UserPromptEvent): void { - QwenLogger.getInstance(config)?.logNewPromptEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -189,7 +188,6 @@ export function logUserPrompt(config: Config, event: UserPromptEvent): void { } export function logUserRetry(config: Config, event: UserRetryEvent): void { - QwenLogger.getInstance(config)?.logRetryEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -215,7 +213,6 @@ export function logToolCall(config: Config, event: ToolCallEvent): void { } as UiEvent; uiTelemetryService.addEvent(uiEvent); config.getChatRecordingService()?.recordUiTelemetryEvent(uiEvent); - QwenLogger.getInstance(config)?.logToolCallEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -250,7 +247,6 @@ export function logToolOutputTruncated( config: Config, event: ToolOutputTruncatedEvent, ): void { - QwenLogger.getInstance(config)?.logToolOutputTruncatedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -272,7 +268,6 @@ export function logFileOperation( config: Config, event: FileOperationEvent, ): void { - QwenLogger.getInstance(config)?.logFileOperationEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -313,7 +308,6 @@ export function logFileOperation( } export function logApiRequest(config: Config, event: ApiRequestEvent): void { - // QwenLogger.getInstance(config)?.logApiRequestEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -335,7 +329,6 @@ export function logFlashFallback( config: Config, event: FlashFallbackEvent, ): void { - QwenLogger.getInstance(config)?.logFlashFallbackEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -357,7 +350,6 @@ export function logRipgrepFallback( config: Config, event: RipgrepFallbackEvent, ): void { - QwenLogger.getInstance(config)?.logRipgrepFallbackEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -383,7 +375,6 @@ export function logApiError(config: Config, event: ApiErrorEvent): void { } as UiEvent; uiTelemetryService.addEvent(uiEvent); config.getChatRecordingService()?.recordUiTelemetryEvent(uiEvent); - QwenLogger.getInstance(config)?.logApiErrorEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -423,7 +414,6 @@ export function logApiCancel(config: Config, event: ApiCancelEvent): void { 'event.timestamp': new Date().toISOString(), } as UiEvent; uiTelemetryService.addEvent(uiEvent); - QwenLogger.getInstance(config)?.logApiCancelEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -450,7 +440,6 @@ export function logApiResponse(config: Config, event: ApiResponseEvent): void { } as UiEvent; uiTelemetryService.addEvent(uiEvent); config.getChatRecordingService()?.recordUiTelemetryEvent(uiEvent); - QwenLogger.getInstance(config)?.logApiResponseEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { ...getCommonAttributes(config), @@ -503,7 +492,6 @@ export function logLoopDetected( config: Config, event: LoopDetectedEvent, ): void { - QwenLogger.getInstance(config)?.logLoopDetectedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -521,16 +509,29 @@ export function logLoopDetected( export function logLoopDetectionDisabled( config: Config, - _event: LoopDetectionDisabledEvent, + event: LoopDetectionDisabledEvent, ): void { - QwenLogger.getInstance(config)?.logLoopDetectionDisabledEvent(); + if (!isTelemetrySdkInitialized()) return; + + const attributes: LogAttributes = { + ...getCommonAttributes(config), + ...event, + 'event.name': EVENT_LOOP_DETECTION_DISABLED, + 'event.timestamp': new Date().toISOString(), + }; + + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: 'Loop detection disabled.', + attributes, + }; + logger.emit(logRecord); } export function logNextSpeakerCheck( config: Config, event: NextSpeakerCheckEvent, ): void { - QwenLogger.getInstance(config)?.logNextSpeakerCheck(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -551,7 +552,6 @@ export function logSlashCommand( config: Config, event: SlashCommandEvent, ): void { - QwenLogger.getInstance(config)?.logSlashCommandEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -572,7 +572,6 @@ export function logIdeConnection( config: Config, event: IdeConnectionEvent, ): void { - QwenLogger.getInstance(config)?.logIdeConnectionEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -593,7 +592,6 @@ export function logConversationFinishedEvent( config: Config, event: ConversationFinishedEvent, ): void { - QwenLogger.getInstance(config)?.logConversationFinishedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -614,8 +612,6 @@ export function logChatCompression( config: Config, event: ChatCompressionEvent, ): void { - QwenLogger.getInstance(config)?.logChatCompressionEvent(event); - const attributes: LogAttributes = { ...getCommonAttributes(config), ...event, @@ -639,7 +635,6 @@ export function logKittySequenceOverflow( config: Config, event: KittySequenceOverflowEvent, ): void { - QwenLogger.getInstance(config)?.logKittySequenceOverflowEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { ...getCommonAttributes(config), @@ -657,7 +652,6 @@ export function logMalformedJsonResponse( config: Config, event: MalformedJsonResponseEvent, ): void { - QwenLogger.getInstance(config)?.logMalformedJsonResponseEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -678,7 +672,6 @@ export function logInvalidChunk( config: Config, event: InvalidChunkEvent, ): void { - QwenLogger.getInstance(config)?.logInvalidChunkEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -704,7 +697,6 @@ export function logContentRetry( config: Config, event: ContentRetryEvent, ): void { - QwenLogger.getInstance(config)?.logContentRetryEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -726,7 +718,6 @@ export function logContentRetryFailure( config: Config, event: ContentRetryFailureEvent, ): void { - QwenLogger.getInstance(config)?.logContentRetryFailureEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -748,7 +739,6 @@ export function logSubagentExecution( config: Config, event: SubagentExecutionEvent, ): void { - QwenLogger.getInstance(config)?.logSubagentExecutionEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -776,7 +766,6 @@ export function logModelSlashCommand( config: Config, event: ModelSlashCommandEvent, ): void { - QwenLogger.getInstance(config)?.logModelSlashCommandEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -795,15 +784,47 @@ export function logModelSlashCommand( } export function logHookCall(config: Config, event: HookCallEvent): void { - // Log to QwenLogger for RUM telemetry only - QwenLogger.getInstance(config)?.logHookCallEvent(event); + if (!isTelemetrySdkInitialized()) return; + + const attributes: LogAttributes = { + ...getCommonAttributes(config), + 'event.name': EVENT_HOOK_CALL, + 'event.timestamp': event['event.timestamp'], + hook_event_name: event.hook_event_name, + hook_type: event.hook_type, + hook_name: event.hook_name, + hook_input: safeJsonStringify(event.hook_input, 2), + duration_ms: event.duration_ms, + success: event.success, + }; + if (event.hook_output !== undefined) { + attributes['hook_output'] = safeJsonStringify(event.hook_output, 2); + } + if (event.exit_code !== undefined) { + attributes['exit_code'] = event.exit_code; + } + if (event.stdout !== undefined) { + attributes['stdout'] = event.stdout; + } + if (event.stderr !== undefined) { + attributes['stderr'] = event.stderr; + } + if (event.error !== undefined) { + attributes['error.message'] = event.error; + } + + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: `Hook call: ${event.hook_name} (${event.hook_event_name}). Success: ${event.success}. Duration: ${event.duration_ms}ms.`, + attributes, + }; + logger.emit(logRecord); } export function logExtensionInstallEvent( config: Config, event: ExtensionInstallEvent, ): void { - QwenLogger.getInstance(config)?.logExtensionInstallEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -829,7 +850,6 @@ export function logExtensionUninstall( config: Config, event: ExtensionUninstallEvent, ): void { - QwenLogger.getInstance(config)?.logExtensionUninstallEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -851,8 +871,6 @@ export async function logExtensionUpdateEvent( config: Config, event: ExtensionUpdateEvent, ): Promise { - QwenLogger.getInstance(config)?.logExtensionUpdateEvent(event); - const attributes: LogAttributes = { ...getCommonAttributes(config), ...event, @@ -877,7 +895,6 @@ export function logExtensionEnable( config: Config, event: ExtensionEnableEvent, ): void { - QwenLogger.getInstance(config)?.logExtensionEnableEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -899,7 +916,6 @@ export function logExtensionDisable( config: Config, event: ExtensionDisableEvent, ): void { - QwenLogger.getInstance(config)?.logExtensionDisableEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -918,7 +934,6 @@ export function logExtensionDisable( } export function logAuth(config: Config, event: AuthEvent): void { - QwenLogger.getInstance(config)?.logAuthEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -972,7 +987,6 @@ export function logUserFeedback( } as UiEvent; uiTelemetryService.addEvent(uiEvent); config.getChatRecordingService()?.recordUiTelemetryEvent(uiEvent); - QwenLogger.getInstance(config)?.logUserFeedbackEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -994,7 +1008,6 @@ export function logArenaSessionStarted( config: Config, event: ArenaSessionStartedEvent, ): void { - QwenLogger.getInstance(config)?.logArenaSessionStartedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -1018,7 +1031,6 @@ export function logArenaAgentCompleted( config: Config, event: ArenaAgentCompletedEvent, ): void { - QwenLogger.getInstance(config)?.logArenaAgentCompletedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { @@ -1048,7 +1060,6 @@ export function logArenaSessionEnded( config: Config, event: ArenaSessionEndedEvent, ): void { - QwenLogger.getInstance(config)?.logArenaSessionEndedEvent(event); if (!isTelemetrySdkInitialized()) return; const attributes: LogAttributes = { diff --git a/packages/core/src/telemetry/qwen-logger/event-types.ts b/packages/core/src/telemetry/qwen-logger/event-types.ts deleted file mode 100644 index f40caa607..000000000 --- a/packages/core/src/telemetry/qwen-logger/event-types.ts +++ /dev/null @@ -1,102 +0,0 @@ -// RUM Protocol Data Structures -export interface RumApp { - id: string; - env: string; - version: string; - type: 'cli' | 'extension'; - channel?: string; -} - -export interface RumUser { - id: string; -} - -export interface RumSession { - id: string; -} - -export interface RumView { - id: string; - name: string; -} - -export interface RumOS { - type?: string; - version?: string; - container?: string; - container_version?: string; -} - -export interface RumDevice { - id?: string; - name?: string; - type?: string; - brand?: string; - model?: string; -} - -export interface RumEvent { - timestamp?: number; - event_type?: 'view' | 'action' | 'exception' | 'resource'; - type: string; // Event type - name: string; // Event name - snapshots?: string; // JSON string of event snapshots - properties?: Record; - // [key: string]: unknown; -} - -export interface RumViewEvent extends RumEvent { - view_type?: string; // View rendering type - time_spent?: number; // Time spent on current view in ms -} - -export interface RumActionEvent extends RumEvent { - target_name?: string; // Element user interacted with (for auto-collected actions only) - duration?: number; // Action duration in ms - method_info?: string; // Action callback, e.g.: onClick() -} - -export interface RumExceptionEvent extends RumEvent { - source?: string; // Error source, e.g.: console, event - file?: string; // Error file - subtype?: string; // Secondary classification of error type - message?: string; // Concise, readable message explaining the event - stack?: string; // Stack trace or supplemental information about the error - caused_by?: string; // Exception cause - line?: number; // Line number where exception occurred - column?: number; // Column number where exception occurred - thread_id?: string; // Thread ID - binary_images?: string; // Error source -} - -export interface RumResourceEvent extends RumEvent { - method?: string; // HTTP request method: POST, GET, etc. - status_code?: string; // Resource status code - message?: string; // Error message content, corresponds to resource.error_msg - url?: string; // Resource URL - provider_type?: string; // Resource provider type: first-party, cdn, ad, analytics - trace_id?: string; // Resource request TraceID - success?: number; // Resource loading success: 1 (default) success, 0 failure - duration?: number; // Total time spent loading resource in ms (responseEnd - redirectStart) - size?: number; // Resource size in bytes, corresponds to decodedBodySize - connect_duration?: number; // Time spent establishing connection to server in ms (connectEnd - connectStart) - ssl_duration?: number; // Time spent on TLS handshake in ms (connectEnd - secureConnectionStart), 0 if no SSL - dns_duration?: number; // Time spent resolving DNS name in ms (domainLookupEnd - domainLookupStart) - redirect_duration?: number; // Time spent on HTTP redirects in ms (redirectEnd - redirectStart) - first_byte_duration?: number; // Time waiting for first byte of response in ms (responseStart - requestStart) - download_duration?: number; // Time spent downloading response in ms (responseEnd - responseStart) - timing_data?: string; // JSON string of PerformanceResourceTiming - trace_data?: string; // Trace information snapshot JSON string -} - -export interface RumPayload { - app: RumApp; - user: RumUser; - session: RumSession; - view: RumView; - os?: RumOS; - device?: RumDevice; - events: RumEvent[]; - properties?: Record; - _v: string; -} diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts deleted file mode 100644 index 282ebe342..000000000 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts +++ /dev/null @@ -1,829 +0,0 @@ -/** - * @license - * Copyright 2025 Google LLC - * SPDX-License-Identifier: Apache-2.0 - */ - -import { - describe, - it, - expect, - vi, - beforeEach, - afterEach, - afterAll, -} from 'vitest'; -import * as os from 'node:os'; -import { QwenLogger, TEST_ONLY } from './qwen-logger.js'; -import type { Config } from '../../config/config.js'; -import { AuthType } from '../../core/contentGenerator.js'; -import { - StartSessionEvent, - EndSessionEvent, - IdeConnectionEvent, - KittySequenceOverflowEvent, - IdeConnectionType, - HookCallEvent, -} from '../types.js'; -import type { RumEvent, RumPayload } from './event-types.js'; - -const debugLoggerSpy = vi.hoisted(() => ({ - debug: vi.fn(), - info: vi.fn(), - warn: vi.fn(), - error: vi.fn(), -})); - -// Mock dependencies -vi.mock('../../utils/user_id.js', () => ({ - getInstallationId: vi.fn(() => 'test-installation-id'), -})); - -vi.mock('../../utils/safeJsonStringify.js', () => ({ - safeJsonStringify: vi.fn((obj) => JSON.stringify(obj)), -})); - -vi.mock('../../utils/debugLogger.js', async (importOriginal) => { - const original = - await importOriginal(); - return { - ...original, - createDebugLogger: () => ({ - debug: debugLoggerSpy.debug, - info: debugLoggerSpy.info, - warn: debugLoggerSpy.warn, - error: debugLoggerSpy.error, - }), - }; -}); - -// Mock https module -vi.mock('https', () => ({ - request: vi.fn(), -})); - -const makeFakeConfig = (overrides: Partial = {}): Config => { - const defaults = { - getUsageStatisticsEnabled: () => true, - getDebugMode: () => false, - getSessionId: () => 'test-session-id', - getCliVersion: () => '1.0.0', - getProxy: () => undefined, - getContentGeneratorConfig: () => ({ authType: 'test-auth' }), - getAuthType: () => AuthType.USE_OPENAI, - getMcpServers: () => ({}), - getModel: () => 'test-model', - getEmbeddingModel: () => 'test-embedding', - getSandbox: () => false, - getCoreTools: () => [], - getApprovalMode: () => 'auto', - getTelemetryEnabled: () => true, - getTelemetryLogPromptsEnabled: () => false, - getFileFilteringRespectGitIgnore: () => true, - getOutputFormat: () => 'text', - getToolRegistry: () => undefined, - getTruncateToolOutputThreshold: () => 25000, - getTruncateToolOutputLines: () => 0, - getIdeMode: () => false, - getShouldUseNodePtyShell: () => false, - getHookSystem: () => undefined, - ...overrides, - }; - return defaults as Config; -}; - -describe('QwenLogger', () => { - let mockConfig: Config; - - beforeEach(() => { - vi.useFakeTimers(); - vi.setSystemTime(new Date('2025-01-01T12:00:00.000Z')); - mockConfig = makeFakeConfig(); - debugLoggerSpy.debug.mockClear(); - debugLoggerSpy.info.mockClear(); - debugLoggerSpy.warn.mockClear(); - debugLoggerSpy.error.mockClear(); - // Clear singleton instance - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (QwenLogger as any).instance = undefined; - }); - - afterEach(() => { - vi.useRealTimers(); - vi.restoreAllMocks(); - }); - - afterAll(() => { - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (QwenLogger as any).instance = undefined; - }); - - describe('getInstance', () => { - it('returns undefined when usage statistics are disabled', () => { - const config = makeFakeConfig({ getUsageStatisticsEnabled: () => false }); - const logger = QwenLogger.getInstance(config); - expect(logger).toBeUndefined(); - }); - - it('returns an instance when usage statistics are enabled', () => { - const logger = QwenLogger.getInstance(mockConfig); - expect(logger).toBeInstanceOf(QwenLogger); - }); - - it('is a singleton', () => { - const logger1 = QwenLogger.getInstance(mockConfig); - const logger2 = QwenLogger.getInstance(mockConfig); - expect(logger1).toBe(logger2); - }); - }); - - describe('createRumPayload', () => { - it('includes os metadata in payload', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const payload = await ( - logger as unknown as { - createRumPayload(): Promise; - } - ).createRumPayload(); - - expect(payload.os).toEqual( - expect.objectContaining({ - type: os.platform(), - version: os.release(), - }), - ); - }); - - it('includes source when source.json exists with valid source', async () => { - // Note: Testing source information requires actual file system operations - // This test verifies that the payload structure is correct - const logger = QwenLogger.getInstance(mockConfig)!; - - const payload = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - - // Verify that payload has app.channel property - expect(payload.app).toHaveProperty('channel'); - // channel should be either undefined or a string - expect( - payload.app.channel === undefined || - typeof payload.app.channel === 'string', - ).toBe(true); - }); - - it('caches source info and does not read file on every payload creation', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Get the cached sourceInfo value - const cachedSourceInfo = logger['sourceInfo']; - - // Create multiple payloads - const payload1 = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - const payload2 = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - - // Both payloads should use the same cached source info - expect(payload1.app.channel).toBe(payload2.app.channel); - // The cached value should not have changed - expect(logger['sourceInfo']).toBe(cachedSourceInfo); - }); - it('does not include source when source.json does not exist', async () => { - // Note: Testing source information requires actual file system operations - // This test verifies the payload structure is correct - const logger = QwenLogger.getInstance(mockConfig)!; - - const payload = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - - // Verify that channel property exists (may be undefined or have a value) - expect(payload.app).toHaveProperty('channel'); - }); - it('does not include source when source value is unknown', async () => { - // Note: Testing source information requires actual file system operations - // This test verifies the payload structure is correct - const logger = QwenLogger.getInstance(mockConfig)!; - - const payload = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - - // Verify that channel property exists - expect(payload.app).toHaveProperty('channel'); - }); - it('handles source.json parsing errors gracefully', async () => { - // Note: Testing source information requires actual file system operations - // This test verifies the payload structure is correct - const logger = QwenLogger.getInstance(mockConfig)!; - - const payload = await ( - logger as unknown as { createRumPayload(): Promise } - ).createRumPayload(); - - // Verify that payload is created successfully (no crash on errors) - expect(payload).toBeDefined(); - expect(payload.app).toHaveProperty('channel'); - }); - }); - - describe('event queue management', () => { - it('should handle event overflow gracefully', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Fill the queue beyond capacity - for (let i = 0; i < TEST_ONLY.MAX_EVENTS + 10; i++) { - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: `test-event-${i}`, - }); - } - - const events = logger['events'].toArray() as RumEvent[]; - expect(logger['events'].size).toBe(TEST_ONLY.MAX_EVENTS); - expect(events[0]?.name).toBe('test-event-10'); - expect(events[events.length - 1]?.name).toBe( - `test-event-${TEST_ONLY.MAX_EVENTS + 9}`, - ); - }); - - it('should handle enqueue errors gracefully', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Mock the events deque to throw an error - const originalPush = logger['events'].push; - logger['events'].push = vi.fn(() => { - throw new Error('Test error'); - }); - - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'test-event', - }); - - expect(logger['events'].size).toBe(0); - - // Restore original method - logger['events'].push = originalPush; - }); - }); - - describe('concurrent flush protection', () => { - it('should handle concurrent flush requests', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Manually set the flush in progress flag to simulate concurrent access - logger['isFlushInProgress'] = true; - - // Try to flush while another flush is in progress - const result = logger.flushToRum(); - - expect(logger['pendingFlush']).toBe(true); - - // Should return a resolved promise - expect(result).toBeInstanceOf(Promise); - - // Reset the flag - logger['isFlushInProgress'] = false; - }); - }); - - describe('failed event retry mechanism', () => { - it('should requeue failed events with size limits', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - const failedEvents: RumEvent[] = []; - for (let i = 0; i < TEST_ONLY.MAX_RETRY_EVENTS + 50; i++) { - failedEvents.push({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: `failed-event-${i}`, - }); - } - - // Call the private method using bracket notation - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (logger as any).requeueFailedEvents(failedEvents); - - expect(logger['events'].size).toBe(TEST_ONLY.MAX_RETRY_EVENTS); - }); - - it('should handle empty retry queue gracefully', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Fill the queue to capacity first - for (let i = 0; i < TEST_ONLY.MAX_EVENTS; i++) { - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: `event-${i}`, - }); - } - - // Try to requeue when no space is available - const failedEvents: RumEvent[] = [ - { - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'failed-event', - }, - ]; - - // eslint-disable-next-line @typescript-eslint/no-explicit-any - (logger as any).requeueFailedEvents(failedEvents); - - expect(logger['events'].size).toBe(TEST_ONLY.MAX_EVENTS); - }); - }); - - describe('event handlers', () => { - it('should log IDE connection events', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new IdeConnectionEvent(IdeConnectionType.SESSION); - - logger.logIdeConnectionEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - event_type: 'action', - type: 'ide', - name: 'ide_connection', - properties: { - connection_type: IdeConnectionType.SESSION, - }, - }), - ); - }); - - it('should log Kitty sequence overflow events', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new KittySequenceOverflowEvent(1024, 'truncated...'); - - logger.logKittySequenceOverflowEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - event_type: 'exception', - type: 'overflow', - name: 'kitty_sequence_overflow', - subtype: 'kitty_sequence_overflow', - properties: { - sequence_length: 1024, - }, - snapshots: JSON.stringify({ - truncated_sequence: 'truncated...', - }), - }), - ); - }); - - it('should flush start session events immediately', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const flushSpy = vi.spyOn(logger, 'flushToRum').mockResolvedValue({}); - - const testConfig = makeFakeConfig({ - getModel: () => 'test-model', - getEmbeddingModel: () => 'test-embedding', - }); - const event = new StartSessionEvent(testConfig); - - logger.logStartSessionEvent(event); - - expect(flushSpy).toHaveBeenCalled(); - }); - - it('should re-read source info when starting a new session', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const readSourceInfoSpy = vi.spyOn( - logger as unknown as { readSourceInfo(): string }, - 'readSourceInfo', - ); - - const testConfig = makeFakeConfig({ - getModel: () => 'test-model', - getEmbeddingModel: () => 'test-embedding', - getSessionId: () => 'new-session-id', - }); - const event = new StartSessionEvent(testConfig); - - await logger.logStartSessionEvent(event); - - // readSourceInfo should be called when starting a new session - expect(readSourceInfoSpy).toHaveBeenCalled(); - // Session ID should be updated - expect(logger['sessionId']).toBe('new-session-id'); - }); - - it('should flush end session events immediately', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const flushSpy = vi.spyOn(logger, 'flushToRum').mockResolvedValue({}); - - const event = new EndSessionEvent(mockConfig); - - logger.logEndSessionEvent(event); - - expect(flushSpy).toHaveBeenCalled(); - }); - }); - - describe('flush timing', () => { - it('should not flush if interval has not passed', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const flushSpy = vi.spyOn(logger, 'flushToRum'); - - // Add an event and try to flush immediately - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'test-event', - }); - - logger.flushIfNeeded(); - - expect(flushSpy).not.toHaveBeenCalled(); - }); - - it('should flush when interval has passed', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const flushSpy = vi.spyOn(logger, 'flushToRum').mockResolvedValue({}); - - // Add an event - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'test-event', - }); - - // Advance time beyond flush interval - vi.advanceTimersByTime(TEST_ONLY.FLUSH_INTERVAL_MS + 1000); - - logger.flushIfNeeded(); - - expect(flushSpy).toHaveBeenCalled(); - }); - }); - - describe('error handling', () => { - it('should handle flush errors gracefully with debug mode', async () => { - const logger = QwenLogger.getInstance(mockConfig)!; - - // Add an event first - logger.enqueueLogEvent({ - timestamp: Date.now(), - event_type: 'action', - type: 'test', - name: 'test-event', - }); - - // Mock flushToRum to throw an error - const originalFlush = logger.flushToRum.bind(logger); - logger.flushToRum = vi.fn().mockRejectedValue(new Error('Network error')); - - // Advance time to trigger flush - vi.advanceTimersByTime(TEST_ONLY.FLUSH_INTERVAL_MS + 1000); - - logger.flushIfNeeded(); - - // Wait for async operations - await vi.runAllTimersAsync(); - - // Errors are now silently ignored to reduce log spam - // Only rate-limited error logs are emitted inside flushToRum itself - - // Restore original method - logger.flushToRum = originalFlush; - }); - }); - - describe('constants export', () => { - it('should export test constants', () => { - expect(TEST_ONLY.MAX_EVENTS).toBe(1000); - expect(TEST_ONLY.MAX_RETRY_EVENTS).toBe(100); - expect(TEST_ONLY.FLUSH_INTERVAL_MS).toBe(60000); - }); - }); - - describe('logHookCallEvent', () => { - it('should log a successful hook call event', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'PreToolUse', - 'command', - 'check-secrets.sh', - { tool_name: 'read_file' }, - 150, - true, - { result: 'valid' }, - 0, - 'stdout', - 'stderr', - undefined, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - event_type: 'action', - type: 'hook', - name: 'hook_call#PreToolUse', - properties: expect.objectContaining({ - hook_event_name: 'PreToolUse', - hook_type: 'command', - hook_name: 'check-secrets.sh', - duration_ms: 150, - success: 1, - exit_code: 0, - }), - }), - ); - }); - - it('should log a failed hook call event with error when telemetry log prompts enabled', () => { - const configWithLogPrompts = makeFakeConfig({ - getTelemetryLogPromptsEnabled: () => true, - }); - const logger = QwenLogger.getInstance(configWithLogPrompts)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'PostToolUse', - 'command', - 'cleanup.sh', - { tool_name: 'shell' }, - 200, - false, - undefined, - 1, - '', - 'error output', - 'Command failed', - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - event_type: 'action', - type: 'hook', - name: 'hook_call#PostToolUse', - properties: expect.objectContaining({ - hook_event_name: 'PostToolUse', - hook_type: 'command', - hook_name: 'cleanup.sh', - duration_ms: 200, - success: 0, - exit_code: 1, - error: 'Command failed', - }), - }), - ); - }); - - it('should not include error when telemetry log prompts disabled', () => { - const configWithoutLogPrompts = makeFakeConfig({ - getTelemetryLogPromptsEnabled: () => false, - }); - // Clear singleton to create new instance with different config - (QwenLogger as unknown as { instance: undefined }).instance = undefined; - const logger = QwenLogger.getInstance(configWithoutLogPrompts)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'PostToolUse', - 'command', - 'cleanup.sh', - { tool_name: 'shell' }, - 200, - false, - undefined, - 1, - '', - 'error output', - 'Command failed with sensitive data', - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - hook_event_name: 'PostToolUse', - hook_type: 'command', - hook_name: 'cleanup.sh', - duration_ms: 200, - success: 0, - exit_code: 1, - }), - }), - ); - - // Error should NOT be in properties - const callArgs = enqueueSpy.mock.calls[0][0]; - expect(callArgs.properties).not.toHaveProperty('error'); - }); - - it('should sanitize hook name to remove sensitive information', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - // Hook name with full path and sensitive arguments - const event = new HookCallEvent( - 'PreToolUse', - 'command', - '/home/user/.qwen/hooks/check-secrets.sh --api-key=secret123', - { tool_name: 'read_file' }, - 100, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - // Should be sanitized to just the basename without arguments - hook_name: 'check-secrets.sh', - }), - }), - ); - }); - - it('should sanitize hook name with Windows path', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'Stop', - 'command', - 'C:\\Users\\user\\hooks\\cleanup.bat --token=xyz', - {}, - 50, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - hook_name: 'cleanup.bat', - }), - }), - ); - }); - - it('should handle empty hook name', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'SessionStart', - 'command', - '', - {}, - 10, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - hook_name: 'unknown-command', - }), - }), - ); - }); - - it('should handle hook name with only whitespace', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'SessionEnd', - 'command', - ' ', - {}, - 10, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - hook_name: 'unknown-command', - }), - }), - ); - }); - - it('should handle hook name that is just a command without path', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const event = new HookCallEvent( - 'Notification', - 'command', - 'python --arg=value', - {}, - 100, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - properties: expect.objectContaining({ - // Should be sanitized to just the command name - hook_name: 'python', - }), - }), - ); - }); - - it('should call flushIfNeeded after logging', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const flushSpy = vi.spyOn(logger, 'flushIfNeeded'); - - const event = new HookCallEvent( - 'PreToolUse', - 'command', - 'test-hook.sh', - {}, - 100, - true, - ); - - logger.logHookCallEvent(event); - - expect(flushSpy).toHaveBeenCalled(); - }); - - it('should handle all hook event types', () => { - const logger = QwenLogger.getInstance(mockConfig)!; - const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); - - const eventTypes = [ - 'PreToolUse', - 'PostToolUse', - 'PostToolUseFailure', - 'Notification', - 'UserPromptSubmit', - 'SessionStart', - 'SessionEnd', - 'Stop', - 'SubagentStart', - 'SubagentStop', - 'PreCompact', - 'PermissionRequest', - ]; - - for (const eventType of eventTypes) { - enqueueSpy.mockClear(); - - const event = new HookCallEvent( - eventType, - 'command', - 'test-hook.sh', - {}, - 100, - true, - ); - - logger.logHookCallEvent(event); - - expect(enqueueSpy).toHaveBeenCalledWith( - expect.objectContaining({ - name: `hook_call#${eventType}`, - properties: expect.objectContaining({ - hook_event_name: eventType, - }), - }), - ); - } - }); - }); -}); diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts deleted file mode 100644 index f22582f05..000000000 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts +++ /dev/null @@ -1,1091 +0,0 @@ -/** - * @license - * Copyright 2025 Google LLC - * SPDX-License-Identifier: Apache-2.0 - */ - -import { Buffer } from 'buffer'; -import * as https from 'https'; -import * as os from 'node:os'; -import fs from 'node:fs'; -import path from 'node:path'; -import { HttpsProxyAgent } from 'https-proxy-agent'; - -import type { - StartSessionEvent, - UserPromptEvent, - ToolCallEvent, - ApiRequestEvent, - ApiResponseEvent, - ApiErrorEvent, - ApiCancelEvent, - FileOperationEvent, - FlashFallbackEvent, - LoopDetectedEvent, - NextSpeakerCheckEvent, - SlashCommandEvent, - MalformedJsonResponseEvent, - IdeConnectionEvent, - KittySequenceOverflowEvent, - ChatCompressionEvent, - InvalidChunkEvent, - ContentRetryEvent, - ContentRetryFailureEvent, - ConversationFinishedEvent, - SubagentExecutionEvent, - ExtensionInstallEvent, - ExtensionUninstallEvent, - ToolOutputTruncatedEvent, - ExtensionEnableEvent, - ModelSlashCommandEvent, - ExtensionDisableEvent, - AuthEvent, - SkillLaunchEvent, - UserFeedbackEvent, - UserRetryEvent, - RipgrepFallbackEvent, - EndSessionEvent, - ExtensionUpdateEvent, - ArenaSessionStartedEvent, - ArenaAgentCompletedEvent, - ArenaSessionEndedEvent, - HookCallEvent, -} from '../types.js'; -import type { - RumEvent, - RumViewEvent, - RumActionEvent, - RumResourceEvent, - RumExceptionEvent, - RumPayload, - RumOS, -} from './event-types.js'; -import type { Config } from '../../config/config.js'; -import { - createDebugLogger, - type DebugLogger, -} from '../../utils/debugLogger.js'; -import { safeJsonStringify } from '../../utils/safeJsonStringify.js'; -import { sanitizeHookName } from '../sanitize.js'; -import { InstallationManager } from '../../utils/installationManager.js'; -import { FixedDeque } from 'mnemonist'; -import { AuthType } from '../../core/contentGenerator.js'; - -// Usage statistics collection endpoint -const USAGE_STATS_HOSTNAME = 'gb4w8c3ygj-default-sea.rum.aliyuncs.com'; -const USAGE_STATS_PATH = '/'; - -const RUN_APP_ID = 'gb4w8c3ygj@851d5d500f08f92'; - -/** - * Interval in which buffered events are sent to RUM. - */ -const FLUSH_INTERVAL_MS = 1000 * 60; - -/** - * Minimum interval between logging network errors to avoid log spam. - */ -const ERROR_LOG_INTERVAL_MS = 5 * 60 * 1000; // 5 minutes - -/** - * Maximum amount of events to keep in memory. Events added after this amount - * are dropped until the next flush to RUM, which happens periodically as - * defined by {@link FLUSH_INTERVAL_MS}. - */ -const MAX_EVENTS = 1000; - -/** - * Maximum events to retry after a failed RUM flush - */ -const MAX_RETRY_EVENTS = 100; - -export interface LogResponse { - nextRequestWaitMs?: number; -} - -// Singleton class for batch posting log events to RUM. When a new event comes in, the elapsed time -// is checked and events are flushed to RUM if at least a minute has passed since the last flush. -export class QwenLogger { - private static instance: QwenLogger; - private config?: Config; - private debugLogger: DebugLogger; - private readonly installationManager: InstallationManager; - - /** - * Queue of pending events that need to be flushed to the server. New events - * are added to this queue and then flushed on demand (via `flushToRum`) - */ - private readonly events: FixedDeque; - - /** - * The last time that the events were successfully flushed to the server. - */ - private lastFlushTime: number = Date.now(); - - private userId: string; - - private sessionId: string; - - /** - * Cached source information read from source.json. - * Only read once at session start to avoid repeated file I/O. - */ - private sourceInfo: string = ''; - - /** - * The value is true when there is a pending flush happening. This prevents - * concurrent flush operations. - */ - private isFlushInProgress: boolean = false; - - /** - * This value is true when a flush was requested during an ongoing flush. - */ - private pendingFlush: boolean = false; - - /** - * Timestamp of the last network error log to prevent log spam. - */ - private lastErrorLogTime: number = 0; - - private constructor(config: Config) { - this.config = config; - this.debugLogger = createDebugLogger('QWEN_LOGGER'); - this.events = new FixedDeque(Array, MAX_EVENTS); - this.installationManager = new InstallationManager(); - this.userId = this.generateUserId(); - this.sessionId = config.getSessionId(); - // Read source info once during initialization - this.sourceInfo = this.readSourceInfo(); - } - - private generateUserId(): string { - // Use InstallationManager to get installationId for userId - const installationId = this.installationManager.getInstallationId(); - return `user-${installationId ?? 'unknown'}`; - } - - static getInstance(config?: Config): QwenLogger | undefined { - if (config === undefined || !config?.getUsageStatisticsEnabled()) - return undefined; - if (!QwenLogger.instance) { - QwenLogger.instance = new QwenLogger(config); - } - - return QwenLogger.instance; - } - - enqueueLogEvent(event: RumEvent): void { - try { - // Manually handle overflow for FixedDeque, which throws when full. - const wasAtCapacity = this.events.size >= MAX_EVENTS; - - if (wasAtCapacity) { - this.events.shift(); // Evict oldest element to make space. - } - - this.events.push(event); - - if (wasAtCapacity) { - this.debugLogger.debug( - `QwenLogger: Dropped old event to prevent memory leak (queue size: ${this.events.size})`, - ); - } - } catch (error) { - this.debugLogger.error('QwenLogger: Failed to enqueue log event.', error); - } - } - - createRumEvent( - eventType: 'view' | 'action' | 'exception' | 'resource', - type: string, - name: string, - properties: Partial, - ): RumEvent { - return { - timestamp: Date.now(), - event_type: eventType, - type, - name, - ...(properties || {}), - }; - } - - createViewEvent( - type: string, - name: string, - properties: Partial, - ): RumEvent { - return this.createRumEvent('view', type, name, properties); - } - - createActionEvent( - type: string, - name: string, - properties: Partial, - ): RumEvent { - return this.createRumEvent('action', type, name, properties); - } - - createResourceEvent( - type: string, - name: string, - properties: Partial, - ): RumEvent { - return this.createRumEvent('resource', type, name, properties); - } - - createExceptionEvent( - type: string, - name: string, - properties: Partial, - ): RumEvent { - return this.createRumEvent('exception', type, name, properties); - } - - private getOsMetadata(): RumOS { - return { - type: os.platform(), - version: os.release(), - }; - } - - async createRumPayload(): Promise { - const authType = this.config?.getAuthType(); - const version = this.config?.getCliVersion() || 'unknown'; - const osMetadata = this.getOsMetadata(); - - // Use cached source information - return { - app: { - id: RUN_APP_ID, - env: process.env['DEBUG'] ? 'dev' : 'prod', - version: version || 'unknown', - type: 'cli', - channel: this.sourceInfo || undefined, - }, - user: { - id: this.userId, - }, - session: { - id: this.sessionId || this.config?.getSessionId(), - }, - view: { - id: this.sessionId || this.config?.getSessionId(), - name: 'qwen-code-cli', - }, - os: osMetadata, - - events: this.events.toArray() as RumEvent[], - properties: { - auth_type: authType, - model: this.config?.getModel(), - base_url: - authType === AuthType.USE_OPENAI - ? this.config?.getContentGeneratorConfig().baseUrl || '' - : '', - ...(this.config?.getChannel?.() - ? { channel: this.config.getChannel() } - : {}), - }, - _v: `qwen-code@${version}`, - } as RumPayload; - } - - flushIfNeeded(): void { - if (Date.now() - this.lastFlushTime < FLUSH_INTERVAL_MS) { - return; - } - - void this.flushToRum(); - } - - readSourceInfo(): string { - try { - const sourceJsonPath = path.join(os.homedir(), '.qwen', 'source.json'); - if (fs.existsSync(sourceJsonPath)) { - const sourceJsonContent = fs.readFileSync(sourceJsonPath, 'utf8'); - const sourceData = JSON.parse(sourceJsonContent); - if ( - sourceData && - typeof sourceData === 'object' && - sourceData.source && - sourceData.source !== 'unknown' - ) { - return sourceData.source; - } - } - } catch (_error) { - // Ignore errors when reading source.json - continue without source info - } - return ''; - } - - async flushToRum(): Promise { - if (this.isFlushInProgress) { - this.debugLogger.debug( - 'QwenLogger: Flush already in progress, marking pending flush.', - ); - this.pendingFlush = true; - return Promise.resolve({}); - } - this.isFlushInProgress = true; - - if (this.events.size === 0) { - this.isFlushInProgress = false; - return {}; - } - - const eventsToSend = this.events.toArray() as RumEvent[]; - this.events.clear(); - - const rumPayload = await this.createRumPayload(); - // Override events with the ones we're sending - rumPayload.events = eventsToSend; - try { - await new Promise((resolve, reject) => { - const body = safeJsonStringify(rumPayload); - const options = { - hostname: USAGE_STATS_HOSTNAME, - path: USAGE_STATS_PATH, - method: 'POST', - headers: { - 'Content-Length': Buffer.byteLength(body), - 'Content-Type': 'text/plain;charset=UTF-8', - }, - }; - const bufs: Buffer[] = []; - const req = https.request( - { - ...options, - agent: this.getProxyAgent(), - }, - (res) => { - if ( - res.statusCode && - (res.statusCode < 200 || res.statusCode >= 300) - ) { - const err = new Error( - `Request failed with status ${res.statusCode}`, - ); - res.resume(); - return reject(err); - } - res.on('data', (buf) => bufs.push(buf)); - res.on('end', () => resolve(Buffer.concat(bufs))); - }, - ); - req.on('error', reject); - req.end(body); - }); - - this.lastFlushTime = Date.now(); - return {}; - } catch (error) { - // Only log network errors if sufficient time has passed to avoid spam - const now = Date.now(); - if (now - this.lastErrorLogTime > ERROR_LOG_INTERVAL_MS) { - this.debugLogger.error('RUM flush failed.', error); - this.lastErrorLogTime = now; - } - - // Re-queue failed events for retry - this.requeueFailedEvents(eventsToSend); - return {}; - } finally { - this.isFlushInProgress = false; - - // If a flush was requested while we were flushing, flush again - if (this.pendingFlush) { - this.pendingFlush = false; - // Fire and forget the pending flush - void this.flushToRum(); - } - } - } - - // session events - async logStartSessionEvent(event: StartSessionEvent): Promise { - // Flush all pending events with the old session ID first. - // If flush fails, discard the pending events to avoid mixing sessions. - await this.flushToRum(); - - // Clear any remaining events (discard if flush failed) - this.events.clear(); - - // Now set the new session ID - this.sessionId = event.session_id; - - // Re-read source info at the start of each new session - this.sourceInfo = this.readSourceInfo(); - - const applicationEvent = this.createViewEvent('session', 'session_start', { - properties: { - approval_mode: event.approval_mode, - core_tools_enabled: event.core_tools_enabled, - debug_enabled: event.debug_enabled, - hooks: event.hooks, - ide_enabled: event.ide_enabled, - interactive_shell_enabled: event.interactive_shell_enabled, - mcp_servers: event.mcp_servers, - model: event.model, - sandbox_enabled: event.sandbox_enabled, - skills: event.skills, - subagents: event.subagents, - telemetry_enabled: event.telemetry_enabled, - truncate_tool_output_lines: event.truncate_tool_output_lines, - truncate_tool_output_threshold: event.truncate_tool_output_threshold, - }, - }); - - // Flush start event immediately - this.enqueueLogEvent(applicationEvent); - void this.flushToRum(); - } - - logEndSessionEvent(_event: EndSessionEvent): void { - const applicationEvent = this.createViewEvent('session', 'session_end', {}); - - // Flush immediately on session end. - this.enqueueLogEvent(applicationEvent); - void this.flushToRum(); - } - - logConversationFinishedEvent(event: ConversationFinishedEvent): void { - const rumEvent = this.createActionEvent( - 'conversation', - 'conversation_finished', - { - properties: { - 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', 'new_prompt', { - properties: { - prompt_id: event.prompt_id, - prompt_length: event.prompt_length, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logRetryEvent(event: UserRetryEvent): void { - const rumEvent = this.createActionEvent('user', 'retry', { - properties: { - prompt_id: event.prompt_id, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logSlashCommandEvent(event: SlashCommandEvent): void { - const rumEvent = this.createActionEvent('user', 'slash_command', { - properties: { - command: event.command, - subcommand: event.subcommand, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logModelSlashCommandEvent(event: ModelSlashCommandEvent): void { - const rumEvent = this.createActionEvent('user', 'model_slash_command', { - properties: { - model: event.model_name, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - // tool call events - logToolCallEvent(event: ToolCallEvent): void { - const rumEvent = this.createActionEvent( - 'tool', - `tool_call#${event.function_name}`, - { - properties: { - prompt_id: event.prompt_id, - response_id: event.response_id, - tool_name: event.function_name, - permission: event.decision, - success: event.success ? 1 : 0, - duration_ms: event.duration_ms, - error_type: event.error_type, - error_message: event.error, - }, - }, - ); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logFileOperationEvent(event: FileOperationEvent): void { - const rumEvent = this.createActionEvent( - 'tool', - `file_operation#${event.tool_name}`, - { - properties: { - tool_name: event.tool_name, - operation: event.operation, - lines: event.lines, - mimetype: event.mimetype, - extension: event.extension, - programming_language: event.programming_language, - }, - }, - ); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logSubagentExecutionEvent(event: SubagentExecutionEvent): void { - const rumEvent = this.createActionEvent('tool', 'subagent_execution', { - properties: { - subagent_name: event.subagent_name, - status: event.status, - terminate_reason: event.terminate_reason, - }, - snapshots: JSON.stringify({ - ...(event.execution_summary - ? { execution_summary: event.execution_summary } - : {}), - }), - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logToolOutputTruncatedEvent(event: ToolOutputTruncatedEvent): void { - const rumEvent = this.createActionEvent('tool', 'tool_output_truncated', { - properties: { - tool_name: event.tool_name, - }, - snapshots: JSON.stringify({ - 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: { - model: event.model, - prompt_id: event.prompt_id, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logApiResponseEvent(event: ApiResponseEvent): void { - const rumEvent = this.createResourceEvent('api', 'api_response', { - status_code: event.status_code?.toString() ?? '', - duration: event.duration_ms, - success: 1, - trace_id: event.response_id, - properties: { - auth_type: event.auth_type, - model: event.model, - prompt_id: event.prompt_id, - }, - snapshots: JSON.stringify({ - input_token_count: event.input_token_count, - output_token_count: event.output_token_count, - cached_content_token_count: event.cached_content_token_count, - thoughts_token_count: event.thoughts_token_count, - tool_token_count: event.tool_token_count, - }), - }); - - this.enqueueLogEvent(rumEvent); - 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() ?? '', - duration: event.duration_ms, - success: 0, - message: event.error_message, - trace_id: event.response_id, - properties: { - auth_type: event.auth_type, - model: event.model, - prompt_id: event.prompt_id, - error_message: event.error_message, - error_type: event.error_type, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - // error events - logInvalidChunkEvent(event: InvalidChunkEvent): void { - const rumEvent = this.createExceptionEvent('error', 'invalid_chunk', { - subtype: 'invalid_chunk', - message: event.error_message, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logContentRetryFailureEvent(event: ContentRetryFailureEvent): void { - const rumEvent = this.createExceptionEvent( - 'error', - 'content_retry_failure', - { - subtype: 'content_retry_failure', - message: `Content retry failed after ${event.total_attempts} attempts`, - properties: { - error_type: event.final_error_type, - total_attempts: event.total_attempts, - total_duration_ms: event.total_duration_ms, - }, - }, - ); - - 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(); - } - - logLoopDetectedEvent(event: LoopDetectedEvent): void { - const rumEvent = this.createExceptionEvent('error', 'loop_detected', { - subtype: 'loop_detected', - properties: { - prompt_id: event.prompt_id, - error_type: event.loop_type, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logKittySequenceOverflowEvent(event: KittySequenceOverflowEvent): void { - const rumEvent = this.createExceptionEvent( - 'overflow', - 'kitty_sequence_overflow', - { - subtype: 'kitty_sequence_overflow', - properties: { - sequence_length: event.sequence_length, - }, - snapshots: JSON.stringify({ - truncated_sequence: event.truncated_sequence, - }), - }, - ); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - // ide events - logIdeConnectionEvent(event: IdeConnectionEvent): void { - const rumEvent = this.createActionEvent('ide', 'ide_connection', { - properties: { - connection_type: event.connection_type, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - // extension events - logExtensionInstallEvent(event: ExtensionInstallEvent): void { - const rumEvent = this.createActionEvent('extension', 'extension_install', { - properties: { - 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', - { - properties: { - extension_name: event.extension_name, - status: event.status, - }, - }, - ); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logExtensionUpdateEvent(event: ExtensionUpdateEvent): void { - const rumEvent = this.createActionEvent('extension', 'extension_update', { - properties: { - extension_name: event.extension_name, - status: event.status, - extension_id: event.extension_id, - extension_previous_version: event.extension_previous_version, - extension_version: event.extension_version, - extension_source: event.extension_source, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logExtensionEnableEvent(event: ExtensionEnableEvent): void { - const rumEvent = this.createActionEvent('extension', 'extension_enable', { - properties: { - 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', { - properties: { - extension_name: event.extension_name, - setting_scope: event.setting_scope, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logAuthEvent(event: AuthEvent): void { - const rumEvent = this.createActionEvent('auth', 'auth', { - properties: { - auth_type: event.auth_type, - action_type: event.action_type, - success: event.status === 'success' ? 1 : 0, - error_type: event.status !== 'success' ? event.status : undefined, - error_message: - event.status === 'error' ? event.error_message : undefined, - }, - }); - - 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(event: RipgrepFallbackEvent): void { - const rumEvent = this.createActionEvent('misc', 'ripgrep_fallback', { - properties: { - platform: process.platform, - arch: process.arch, - use_ripgrep: event.use_ripgrep, - use_builtin_ripgrep: event.use_builtin_ripgrep, - error_message: event.error, - }, - }); - - 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, - finish_reason: event.finish_reason, - result: event.result, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logSkillLaunchEvent(event: SkillLaunchEvent): void { - const rumEvent = this.createActionEvent('misc', 'skill_launch', { - properties: { - skill_name: event.skill_name, - success: event.success ? 1 : 0, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logUserFeedbackEvent(event: UserFeedbackEvent): void { - const rumEvent = this.createActionEvent('user', 'user_feedback', { - properties: { - session_id: event.session_id, - rating: event.rating, - model: event.model, - approval_mode: event.approval_mode, - prompt_id: event.prompt_id || '', - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logChatCompressionEvent(event: ChatCompressionEvent): void { - const rumEvent = this.createActionEvent('misc', 'chat_compression', { - properties: { - 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', { - properties: { - error_type: event.error_type, - attempt_number: event.attempt_number, - retry_delay_ms: event.retry_delay_ms, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - // arena events - logArenaSessionStartedEvent(event: ArenaSessionStartedEvent): void { - const rumEvent = this.createActionEvent('arena', 'arena_session_started', { - properties: { - arena_session_id: event.arena_session_id, - model_ids: JSON.stringify(event.model_ids), - task_length: event.task_length, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logArenaAgentCompletedEvent(event: ArenaAgentCompletedEvent): void { - const rumEvent = this.createActionEvent('arena', 'arena_agent_completed', { - properties: { - arena_session_id: event.arena_session_id, - agent_session_id: event.agent_session_id, - agent_model_id: event.agent_model_id, - status: event.status, - duration_ms: event.duration_ms, - rounds: event.rounds, - total_tokens: event.total_tokens, - input_tokens: event.input_tokens, - output_tokens: event.output_tokens, - tool_calls: event.tool_calls, - successful_tool_calls: event.successful_tool_calls, - failed_tool_calls: event.failed_tool_calls, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - logArenaSessionEndedEvent(event: ArenaSessionEndedEvent): void { - const rumEvent = this.createActionEvent('arena', 'arena_session_ended', { - properties: { - arena_session_id: event.arena_session_id, - status: event.status, - duration_ms: event.duration_ms, - display_backend: event.display_backend, - agent_count: event.agent_count, - completed_agents: event.completed_agents, - failed_agents: event.failed_agents, - cancelled_agents: event.cancelled_agents, - winner_model_id: event.winner_model_id, - }, - }); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - /** - * Log a hook call event - * Records hook execution telemetry for observability - */ - logHookCallEvent(event: HookCallEvent): void { - // Sanitize hook name to remove potentially sensitive information - const sanitizedHookName = sanitizeHookName(event.hook_name); - - const properties: Record = { - hook_event_name: event.hook_event_name, - hook_type: event.hook_type, - hook_name: sanitizedHookName, - duration_ms: event.duration_ms, - success: event.success ? 1 : 0, - exit_code: event.exit_code, - }; - - if (event.error && this.config?.getTelemetryLogPromptsEnabled()) { - properties['error'] = event.error; - } - - const rumEvent = this.createActionEvent( - 'hook', - `hook_call#${event.hook_event_name}`, - { properties }, - ); - - this.enqueueLogEvent(rumEvent); - this.flushIfNeeded(); - } - - getProxyAgent() { - const proxyUrl = this.config?.getProxy(); - if (!proxyUrl) return undefined; - // undici which is widely used in the repo can only support http & https proxy protocol, - // https://github.com/nodejs/undici/issues/2224 - if (proxyUrl.startsWith('http')) { - return new HttpsProxyAgent(proxyUrl); - } else { - throw new Error('Unsupported proxy type'); - } - } - - private requeueFailedEvents(eventsToSend: RumEvent[]): void { - // Add the events back to the front of the queue to be retried, but limit retry queue size - const eventsToRetry = eventsToSend.slice(-MAX_RETRY_EVENTS); // Keep only the most recent events - - // Log a warning if we're dropping events - if (eventsToSend.length > MAX_RETRY_EVENTS) { - this.debugLogger.warn( - `QwenLogger: Dropping ${ - eventsToSend.length - MAX_RETRY_EVENTS - } events due to retry queue limit. Total events: ${ - eventsToSend.length - }, keeping: ${MAX_RETRY_EVENTS}`, - ); - } - - // Determine how many events can be re-queued - const availableSpace = MAX_EVENTS - this.events.size; - const numEventsToRequeue = Math.min(eventsToRetry.length, availableSpace); - - if (numEventsToRequeue === 0) { - return; - } - - // Get the most recent events to re-queue - const eventsToRequeue = eventsToRetry.slice( - eventsToRetry.length - numEventsToRequeue, - ); - - // Prepend events to the front of the deque to be retried first. - // We iterate backwards to maintain the original order of the failed events. - for (let i = eventsToRequeue.length - 1; i >= 0; i--) { - this.events.unshift(eventsToRequeue[i]); - } - // Clear any potential overflow - while (this.events.size > MAX_EVENTS) { - this.events.pop(); - } - - this.debugLogger.debug( - `QwenLogger: Re-queued ${numEventsToRequeue} events for retry (queue size: ${this.events.size})`, - ); - } -} - -export const TEST_ONLY = { - MAX_RETRY_EVENTS, - MAX_EVENTS, - FLUSH_INTERVAL_MS, -}; diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index f5a62c38d..fbf60cb67 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -803,7 +803,8 @@ export class AuthEvent implements BaseTelemetryEvent { } /** - * Hook call telemetry event + * Hook call telemetry event — captures user-defined hook executions + * (UserPromptSubmit, PreToolUse, etc.) for Langfuse observability. */ export class HookCallEvent implements BaseTelemetryEvent { 'event.name': string;