From b9236046029ff01e898f95c8115baa94ca3993eb Mon Sep 17 00:00:00 2001 From: Abhi <43648792+abhipatel12@users.noreply.github.com> Date: Sun, 21 Dec 2025 16:18:42 -0500 Subject: [PATCH] feat(telemetry): add clearcut logging for hooks (#15405) --- .../core/src/hooks/hookEventHandler.test.ts | 8 +++ .../clearcut-logger/clearcut-logger.test.ts | 41 ++++++++++++ .../clearcut-logger/clearcut-logger.ts | 29 +++++++++ .../clearcut-logger/event-metadata-key.ts | 18 +++++- packages/core/src/telemetry/loggers.test.ts | 63 +++++++++++++++++++ packages/core/src/telemetry/loggers.ts | 1 + 6 files changed, 159 insertions(+), 1 deletion(-) diff --git a/packages/core/src/hooks/hookEventHandler.test.ts b/packages/core/src/hooks/hookEventHandler.test.ts index b2c0a80e23..e30a57ba87 100644 --- a/packages/core/src/hooks/hookEventHandler.test.ts +++ b/packages/core/src/hooks/hookEventHandler.test.ts @@ -40,6 +40,14 @@ vi.mock('../utils/events.js', () => ({ coreEvents: mockCoreEvents, })); +vi.mock('../telemetry/clearcut-logger/clearcut-logger.js', () => ({ + ClearcutLogger: { + getInstance: vi.fn().mockReturnValue({ + logHookCallEvent: vi.fn(), + }), + }, +})); + describe('HookEventHandler', () => { let hookEventHandler: HookEventHandler; let mockConfig: Config; diff --git a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts index d66cf67b00..9a4c811774 100644 --- a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts +++ b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.test.ts @@ -33,6 +33,7 @@ import { AgentStartEvent, AgentFinishEvent, WebFetchFallbackAttemptEvent, + HookCallEvent, } from '../types.js'; import { AgentTerminateMode } from '../../agents/types.js'; import { GIT_COMMIT_INFO, CLI_VERSION } from '../../generated/git-commit.js'; @@ -1102,4 +1103,44 @@ describe('ClearcutLogger', () => { ]); }); }); + + describe('logHookCallEvent', () => { + it('logs an event with proper fields', () => { + const { logger } = setup(); + const hookName = '/path/to/my/script.sh'; + + const event = new HookCallEvent( + 'before-tool', + 'command', + hookName, + {}, // input + 150, // duration + true, // success + {}, // output + 0, // exit code + ); + + logger?.logHookCallEvent(event); + + const events = getEvents(logger!); + expect(events.length).toBe(1); + expect(events[0]).toHaveEventName(EventNames.HOOK_CALL); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_HOOK_EVENT_NAME, + 'before-tool', + ]); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_HOOK_DURATION_MS, + '150', + ]); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_HOOK_SUCCESS, + 'true', + ]); + expect(events[0]).toHaveMetadataValue([ + EventMetadataKey.GEMINI_CLI_HOOK_EXIT_CODE, + '0', + ]); + }); + }); }); diff --git a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts index e4535fdf48..e52669b3a3 100644 --- a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts +++ b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts @@ -39,6 +39,7 @@ import type { WebFetchFallbackAttemptEvent, ExtensionUpdateEvent, LlmLoopCheckEvent, + HookCallEvent, } from '../types.js'; import { EventMetadataKey } from './event-metadata-key.js'; import type { Config } from '../../config/config.js'; @@ -95,6 +96,7 @@ export enum EventNames { RECOVERY_ATTEMPT = 'recovery_attempt', WEB_FETCH_FALLBACK_ATTEMPT = 'web_fetch_fallback_attempt', LLM_LOOP_CHECK = 'llm_loop_check', + HOOK_CALL = 'hook_call', } export interface LogResponse { @@ -1381,6 +1383,33 @@ export class ClearcutLogger { this.flushIfNeeded(); } + logHookCallEvent(event: HookCallEvent): void { + const data: EventValue[] = [ + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_HOOK_EVENT_NAME, + value: event.hook_event_name, + }, + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_HOOK_DURATION_MS, + value: event.duration_ms.toString(), + }, + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_HOOK_SUCCESS, + value: event.success.toString(), + }, + ]; + + if (event.exit_code !== undefined) { + data.push({ + gemini_cli_key: EventMetadataKey.GEMINI_CLI_HOOK_EXIT_CODE, + value: event.exit_code.toString(), + }); + } + + this.enqueueLogEvent(this.createLogEvent(EventNames.HOOK_CALL, data)); + this.flushIfNeeded(); + } + /** * Adds default fields to data, and returns a new data array. This fields * should exist on all log events. diff --git a/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts b/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts index dc7ad7d672..ce3e3ee10c 100644 --- a/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts +++ b/packages/core/src/telemetry/clearcut-logger/event-metadata-key.ts @@ -7,7 +7,7 @@ // Defines valid event metadata keys for Clearcut logging. export enum EventMetadataKey { // Deleted enums: 24 - // Next ID: 133 + // Next ID: 137 GEMINI_CLI_KEY_UNKNOWN = 0, @@ -501,4 +501,20 @@ export enum EventMetadataKey { // Logs the model that confirmed the loop. GEMINI_CLI_LOOP_DETECTED_CONFIRMED_BY_MODEL = 129, + + // ========================================================================== + // Hook Call Event Keys + // ========================================================================== + + // Logs the name of the hook event (e.g., 'BeforeTool', 'AfterModel'). + GEMINI_CLI_HOOK_EVENT_NAME = 133, + + // Logs the duration of the hook execution in milliseconds. + GEMINI_CLI_HOOK_DURATION_MS = 134, + + // Logs whether the hook execution was successful. + GEMINI_CLI_HOOK_SUCCESS = 135, + + // Logs the exit code of the hook script (if applicable). + GEMINI_CLI_HOOK_EXIT_CODE = 136, } diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index a7b89d1003..bd0f387bc1 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -43,6 +43,7 @@ import { logAgentFinish, logWebFetchFallbackAttempt, logExtensionUpdateEvent, + logHookCall, } from './loggers.js'; import { ToolCallDecision } from './tool-call-decision.js'; import { @@ -87,6 +88,8 @@ import { WebFetchFallbackAttemptEvent, ExtensionUpdateEvent, EVENT_EXTENSION_UPDATE, + HookCallEvent, + EVENT_HOOK_CALL, } from './types.js'; import * as metrics from './metrics.js'; import { FileOperation } from './metrics.js'; @@ -2101,6 +2104,66 @@ describe('loggers', () => { }); }); }); + + describe('logHookCall', () => { + const mockConfig = { + getSessionId: () => 'test-session-id', + getUsageStatisticsEnabled: () => true, + isInteractive: () => false, + getTelemetryLogPromptsEnabled: () => false, + } as unknown as Config; + + beforeEach(() => { + vi.spyOn(ClearcutLogger.prototype, 'logHookCallEvent'); + vi.spyOn(metrics, 'recordHookCallMetrics'); + }); + + it('should log hook call event to Clearcut and OTEL', () => { + const event = new HookCallEvent( + 'before-tool', + 'command', + '/path/to/script.sh', + { arg: 'val' }, + 150, + true, + { out: 'res' }, + 0, + ); + + logHookCall(mockConfig, event); + + expect(ClearcutLogger.prototype.logHookCallEvent).toHaveBeenCalledWith( + event, + ); + + expect(mockLogger.emit).toHaveBeenCalledWith({ + body: 'Hook call before-tool./path/to/script.sh succeeded in 150ms', + attributes: { + 'session.id': 'test-session-id', + 'user.email': 'test-user@example.com', + 'installation.id': 'test-installation-id', + 'event.name': EVENT_HOOK_CALL, + 'event.timestamp': '2025-01-01T00:00:00.000Z', + interactive: false, + hook_event_name: 'before-tool', + hook_type: 'command', + hook_name: 'script.sh', // Sanitized because logPrompts is false + duration_ms: 150, + success: true, + exit_code: 0, + }, + }); + + expect(metrics.recordHookCallMetrics).toHaveBeenCalledWith( + mockConfig, + 'before-tool', + '/path/to/script.sh', + 150, + true, + ); + }); + }); + describe('Telemetry Buffering', () => { it('should buffer events when SDK is not initialized', () => { vi.spyOn(sdk, 'isTelemetrySdkInitialized').mockReturnValue(false); diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index 8a2c08f2a5..11858c9117 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -672,6 +672,7 @@ export function logLlmLoopCheck( } export function logHookCall(config: Config, event: HookCallEvent): void { + ClearcutLogger.getInstance(config)?.logHookCallEvent(event); bufferTelemetryEvent(() => { const logger = logs.getLogger(SERVICE_NAME); const logRecord: LogRecord = {