feat(hooks): Hook Telemetry Infrastructure (#9082)

This commit is contained in:
Edilmo Palencia
2025-11-24 13:13:24 -08:00
committed by GitHub
parent e50bf6adad
commit f6ee025c46
6 changed files with 810 additions and 0 deletions

View File

@@ -49,6 +49,7 @@ import type {
WebFetchFallbackAttemptEvent,
ExtensionUpdateEvent,
LlmLoopCheckEvent,
HookCallEvent,
} from './types.js';
import {
recordApiErrorMetrics,
@@ -66,6 +67,7 @@ import {
recordAgentRunMetrics,
recordRecoveryAttemptMetrics,
recordLinesChanged,
recordHookCallMetrics,
} from './metrics.js';
import { isTelemetrySdkInitialized } from './sdk.js';
import type { UiEvent } from './uiTelemetry.js';
@@ -670,3 +672,22 @@ export function logLlmLoopCheck(
};
logger.emit(logRecord);
}
export function logHookCall(config: Config, event: HookCallEvent): void {
if (!isTelemetrySdkInitialized()) return;
const logger = logs.getLogger(SERVICE_NAME);
const logRecord: LogRecord = {
body: event.toLogBody(),
attributes: event.toOpenTelemetryAttributes(config),
};
logger.emit(logRecord);
recordHookCallMetrics(
config,
event.hook_event_name,
event.hook_name,
event.duration_ms,
event.success,
);
}

View File

@@ -1342,5 +1342,115 @@ describe('Telemetry Metrics', () => {
expect(mockHistogramRecordFn).not.toHaveBeenCalled();
});
});
describe('recordHookCallMetrics', () => {
let recordHookCallMetricsModule: typeof import('./metrics.js').recordHookCallMetrics;
beforeEach(async () => {
recordHookCallMetricsModule = (await import('./metrics.js'))
.recordHookCallMetrics;
});
it('should record hook call metrics with counter and histogram', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
mockHistogramRecordFn.mockClear();
recordHookCallMetricsModule(
mockConfig,
'BeforeTool',
'test-hook',
150,
true,
);
// Verify counter recorded
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
'installation.id': 'test-installation-id',
'user.email': 'test@example.com',
hook_event_name: 'BeforeTool',
hook_name: 'test-hook',
success: true,
});
// Verify histogram recorded
expect(mockHistogramRecordFn).toHaveBeenCalledWith(150, {
'session.id': 'test-session-id',
'installation.id': 'test-installation-id',
'user.email': 'test@example.com',
hook_event_name: 'BeforeTool',
hook_name: 'test-hook',
success: true,
});
});
it('should always sanitize hook names regardless of content', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
// Test with a command that has sensitive information
recordHookCallMetricsModule(
mockConfig,
'BeforeTool',
'/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123',
150,
true,
);
// Verify hook name is sanitized (detailed sanitization tested in hook-call-event.test.ts)
expect(mockCounterAddFn).toHaveBeenCalledWith(1, {
'session.id': 'test-session-id',
'installation.id': 'test-installation-id',
'user.email': 'test@example.com',
hook_event_name: 'BeforeTool',
hook_name: 'check-secrets.sh', // Sanitized
success: true,
});
});
it('should track both success and failure', () => {
initializeMetricsModule(mockConfig);
mockCounterAddFn.mockClear();
// Success case
recordHookCallMetricsModule(
mockConfig,
'BeforeTool',
'test-hook',
100,
true,
);
expect(mockCounterAddFn).toHaveBeenNthCalledWith(
1,
1,
expect.objectContaining({
hook_event_name: 'BeforeTool',
hook_name: 'test-hook',
success: true,
}),
);
// Failure case
recordHookCallMetricsModule(
mockConfig,
'AfterTool',
'test-hook',
150,
false,
);
expect(mockCounterAddFn).toHaveBeenNthCalledWith(
2,
1,
expect.objectContaining({
hook_event_name: 'AfterTool',
hook_name: 'test-hook',
success: false,
}),
);
});
});
});
});

View File

@@ -16,6 +16,7 @@ import type {
} from './types.js';
import { AuthType } from '../core/contentGenerator.js';
import { getCommonAttributes } from './telemetryAttributes.js';
import { sanitizeHookName } from './sanitize.js';
const EVENT_CHAT_COMPRESSION = 'gemini_cli.chat_compression';
const TOOL_CALL_COUNT = 'gemini_cli.tool.call.count';
@@ -34,6 +35,8 @@ const MODEL_ROUTING_LATENCY = 'gemini_cli.model_routing.latency';
const MODEL_ROUTING_FAILURE_COUNT = 'gemini_cli.model_routing.failure.count';
const MODEL_SLASH_COMMAND_CALL_COUNT =
'gemini_cli.slash_command.model.call_count';
const EVENT_HOOK_CALL_COUNT = 'gemini_cli.hook_call.count';
const EVENT_HOOK_CALL_LATENCY = 'gemini_cli.hook_call.latency';
// Agent Metrics
const AGENT_RUN_COUNT = 'gemini_cli.agent.run.count';
@@ -202,6 +205,16 @@ const COUNTER_DEFINITIONS = {
assign: (c: Counter) => (exitFailCounter = c),
attributes: {} as Record<string, never>,
},
[EVENT_HOOK_CALL_COUNT]: {
description: 'Counts hook calls, tagged by hook event name and success.',
valueType: ValueType.INT,
assign: (c: Counter) => (hookCallCounter = c),
attributes: {} as {
hook_event_name: string;
hook_name: string;
success: boolean;
},
},
} as const;
const HISTOGRAM_DEFINITIONS = {
@@ -297,6 +310,17 @@ const HISTOGRAM_DEFINITIONS = {
'error.type'?: string;
},
},
[EVENT_HOOK_CALL_LATENCY]: {
description: 'Latency of hook calls in milliseconds.',
unit: 'ms',
valueType: ValueType.INT,
assign: (c: Histogram) => (hookCallLatencyHistogram = c),
attributes: {} as {
hook_event_name: string;
hook_name: string;
success: boolean;
},
},
} as const;
const PERFORMANCE_COUNTER_DEFINITIONS = {
@@ -506,6 +530,8 @@ let agentRecoveryAttemptDurationHistogram: Histogram | undefined;
let flickerFrameCounter: Counter | undefined;
let exitFailCounter: Counter | undefined;
let slowRenderHistogram: Histogram | undefined;
let hookCallCounter: Counter | undefined;
let hookCallLatencyHistogram: Histogram | undefined;
// OpenTelemetry GenAI Semantic Convention Metrics
let genAiClientTokenUsageHistogram: Histogram | undefined;
@@ -1162,3 +1188,27 @@ export function recordApiResponseMetrics(
});
}
}
export function recordHookCallMetrics(
config: Config,
hookEventName: string,
hookName: string,
durationMs: number,
success: boolean,
): void {
if (!hookCallCounter || !hookCallLatencyHistogram || !isMetricsInitialized)
return;
// Always sanitize hook names in metrics (metrics are aggregated and exposed)
const sanitizedHookName = sanitizeHookName(hookName);
const metricAttributes: Attributes = {
...baseMetricDefinition.getCommonAttributes(config),
hook_event_name: hookEventName,
hook_name: sanitizedHookName,
success,
};
hookCallCounter.add(1, metricAttributes);
hookCallLatencyHistogram.record(durationMs, metricAttributes);
}

View File

@@ -0,0 +1,493 @@
/**
* @license
* Copyright 2025 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
/**
* Tests for telemetry sanitization functions.
*
* This test file focuses on validating PII protection through sanitization,
* particularly for hook names that may contain sensitive information like
* API keys, credentials, file paths, and command arguments.
*/
import { describe, it, expect } from 'vitest';
import { HookCallEvent, EVENT_HOOK_CALL } from './types.js';
import type { Config } from '../config/config.js';
/**
* Create a mock config for testing.
*
* @param logPromptsEnabled Whether telemetry logging of prompts is enabled.
* @returns Mock config object.
*/
function createMockConfig(logPromptsEnabled: boolean): Config {
return {
getTelemetryLogPromptsEnabled: () => logPromptsEnabled,
getSessionId: () => 'test-session-id',
getModel: () => 'gemini-1.5-flash',
isInteractive: () => true,
getUserEmail: () => undefined,
} as unknown as Config;
}
describe('Telemetry Sanitization', () => {
describe('HookCallEvent', () => {
describe('constructor', () => {
it('should create an event with all fields', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'test-hook',
{ tool_name: 'ReadFile' },
100,
true,
{ decision: 'allow' },
0,
'output',
'error',
undefined,
);
expect(event['event.name']).toBe('hook_call');
expect(event.hook_event_name).toBe('BeforeTool');
expect(event.hook_type).toBe('command');
expect(event.hook_name).toBe('test-hook');
expect(event.hook_input).toEqual({ tool_name: 'ReadFile' });
expect(event.hook_output).toEqual({ decision: 'allow' });
expect(event.exit_code).toBe(0);
expect(event.stdout).toBe('output');
expect(event.stderr).toBe('error');
expect(event.duration_ms).toBe(100);
expect(event.success).toBe(true);
expect(event.error).toBeUndefined();
});
it('should create an event with minimal fields', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'test-hook',
{ tool_name: 'ReadFile' },
100,
true,
);
expect(event.hook_output).toBeUndefined();
expect(event.exit_code).toBeUndefined();
expect(event.stdout).toBeUndefined();
expect(event.stderr).toBeUndefined();
expect(event.error).toBeUndefined();
});
});
describe('toOpenTelemetryAttributes with logPrompts=true', () => {
const config = createMockConfig(true);
it('should include all fields when logPrompts is enabled', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123',
{ tool_name: 'ReadFile', args: { file: 'secret.txt' } },
100,
true,
{ decision: 'allow' },
0,
'hook executed successfully',
'no errors',
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['event.name']).toBe(EVENT_HOOK_CALL);
expect(attributes['hook_event_name']).toBe('BeforeTool');
expect(attributes['hook_type']).toBe('command');
// With logPrompts=true, full hook name is included
expect(attributes['hook_name']).toBe(
'/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123',
);
expect(attributes['duration_ms']).toBe(100);
expect(attributes['success']).toBe(true);
expect(attributes['exit_code']).toBe(0);
// PII-sensitive fields should be included
expect(attributes['hook_input']).toBeDefined();
expect(attributes['hook_output']).toBeDefined();
expect(attributes['stdout']).toBe('hook executed successfully');
expect(attributes['stderr']).toBe('no errors');
});
it('should include hook_input and hook_output as JSON strings', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'test-hook',
{ tool_name: 'ReadFile', args: { file: 'test.txt' } },
100,
true,
{ decision: 'allow', reason: 'approved' },
);
const attributes = event.toOpenTelemetryAttributes(config);
// Should be JSON stringified
expect(typeof attributes['hook_input']).toBe('string');
expect(typeof attributes['hook_output']).toBe('string');
const parsedInput = JSON.parse(attributes['hook_input'] as string);
expect(parsedInput).toEqual({
tool_name: 'ReadFile',
args: { file: 'test.txt' },
});
const parsedOutput = JSON.parse(attributes['hook_output'] as string);
expect(parsedOutput).toEqual({ decision: 'allow', reason: 'approved' });
});
});
describe('toOpenTelemetryAttributes with logPrompts=false', () => {
const config = createMockConfig(false);
it('should exclude PII-sensitive fields when logPrompts is disabled', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123',
{ tool_name: 'ReadFile', args: { file: 'secret.txt' } },
100,
true,
{ decision: 'allow' },
0,
'hook executed successfully',
'no errors',
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['event.name']).toBe(EVENT_HOOK_CALL);
expect(attributes['hook_event_name']).toBe('BeforeTool');
expect(attributes['hook_type']).toBe('command');
expect(attributes['duration_ms']).toBe(100);
expect(attributes['success']).toBe(true);
expect(attributes['exit_code']).toBe(0);
// PII-sensitive fields should NOT be included
expect(attributes['hook_input']).toBeUndefined();
expect(attributes['hook_output']).toBeUndefined();
expect(attributes['stdout']).toBeUndefined();
expect(attributes['stderr']).toBeUndefined();
});
it('should sanitize hook_name when logPrompts is disabled', () => {
const testCases = [
{
input: '/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123',
expected: 'check-secrets.sh',
description: 'full path with arguments',
},
{
input: 'python /home/user/script.py --token=xyz',
expected: 'python',
description: 'command with script path and token',
},
{
input: 'node index.js',
expected: 'node',
description: 'simple command with file',
},
{
input: '/usr/bin/bash -c "echo $SECRET"',
expected: 'bash',
description: 'path with inline script',
},
{
input: 'C:\\Windows\\System32\\cmd.exe /c secret.bat',
expected: 'cmd.exe',
description: 'Windows path with arguments',
},
{
input: './hooks/local-hook.sh',
expected: 'local-hook.sh',
description: 'relative path',
},
{
input: 'simple-command',
expected: 'simple-command',
description: 'command without path or args',
},
{
input: '',
expected: 'unknown-command',
description: 'empty string',
},
{
input: ' ',
expected: 'unknown-command',
description: 'whitespace only',
},
];
for (const testCase of testCases) {
const event = new HookCallEvent(
'BeforeTool',
'command',
testCase.input,
{ tool_name: 'ReadFile' },
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe(testCase.expected);
}
});
it('should still include error field even when logPrompts is disabled', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'test-hook',
{ tool_name: 'ReadFile' },
100,
false,
undefined,
undefined,
undefined,
undefined,
'Hook execution failed',
);
const attributes = event.toOpenTelemetryAttributes(config);
// Error should be included for debugging
expect(attributes['error']).toBe('Hook execution failed');
// But other PII fields should not
expect(attributes['hook_input']).toBeUndefined();
expect(attributes['stdout']).toBeUndefined();
});
});
describe('sanitizeHookName edge cases', () => {
const config = createMockConfig(false);
it('should handle commands with multiple spaces', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'python script.py --arg1 --arg2',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('python');
});
it('should handle mixed path separators', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'/path/to\\mixed\\separators.sh',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('separators.sh');
});
it('should handle trailing slashes', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'/path/to/directory/',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('unknown-command');
});
});
describe('toLogBody', () => {
it('should format success message correctly', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'test-hook',
{},
150,
true,
);
expect(event.toLogBody()).toBe(
'Hook call BeforeTool.test-hook succeeded in 150ms',
);
});
it('should format failure message correctly', () => {
const event = new HookCallEvent(
'AfterTool',
'command',
'validation-hook',
{},
75,
false,
);
expect(event.toLogBody()).toBe(
'Hook call AfterTool.validation-hook failed in 75ms',
);
});
});
describe('integration scenarios', () => {
it('should handle enterprise scenario with full logging', () => {
const enterpriseConfig = createMockConfig(true);
const event = new HookCallEvent(
'BeforeModel',
'command',
'$GEMINI_PROJECT_DIR/.gemini/hooks/add-context.sh',
{
llm_request: {
model: 'gemini-1.5-flash',
messages: [{ role: 'user', content: 'Hello' }],
},
},
250,
true,
{
hookSpecificOutput: {
llm_request: {
messages: [
{ role: 'user', content: 'Hello' },
{ role: 'system', content: 'Additional context...' },
],
},
},
},
0,
'Context added successfully',
);
const attributes = event.toOpenTelemetryAttributes(enterpriseConfig);
// In enterprise mode, everything is logged
expect(attributes['hook_name']).toBe(
'$GEMINI_PROJECT_DIR/.gemini/hooks/add-context.sh',
);
expect(attributes['hook_input']).toBeDefined();
expect(attributes['hook_output']).toBeDefined();
expect(attributes['stdout']).toBe('Context added successfully');
});
it('should handle public telemetry scenario with minimal logging', () => {
const publicConfig = createMockConfig(false);
const event = new HookCallEvent(
'BeforeModel',
'command',
'$GEMINI_PROJECT_DIR/.gemini/hooks/add-context.sh',
{
llm_request: {
model: 'gemini-1.5-flash',
messages: [{ role: 'user', content: 'Hello' }],
},
},
250,
true,
{
hookSpecificOutput: {
llm_request: {
messages: [
{ role: 'user', content: 'Hello' },
{ role: 'system', content: 'Additional context...' },
],
},
},
},
0,
'Context added successfully',
);
const attributes = event.toOpenTelemetryAttributes(publicConfig);
// In public mode, only metadata
expect(attributes['hook_name']).toBe('add-context.sh');
expect(attributes['hook_input']).toBeUndefined();
expect(attributes['hook_output']).toBeUndefined();
expect(attributes['stdout']).toBeUndefined();
// But metadata is still there
expect(attributes['hook_event_name']).toBe('BeforeModel');
expect(attributes['duration_ms']).toBe(250);
expect(attributes['success']).toBe(true);
});
});
describe('real-world sensitive command examples', () => {
const config = createMockConfig(false);
it('should sanitize commands with API keys', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'curl https://api.example.com -H "Authorization: Bearer sk-abc123xyz"',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('curl');
});
it('should sanitize commands with database credentials', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'psql postgresql://user:password@localhost/db',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('psql');
});
it('should sanitize commands with environment variables containing secrets', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'AWS_SECRET_KEY=abc123 aws s3 ls',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('AWS_SECRET_KEY=abc123');
});
it('should sanitize Python scripts with file paths', () => {
const event = new HookCallEvent(
'BeforeTool',
'command',
'python /home/john.doe/projects/secret-scanner/scan.py --config=/etc/secrets.yml',
{},
100,
true,
);
const attributes = event.toOpenTelemetryAttributes(config);
expect(attributes['hook_name']).toBe('python');
});
});
});
});

View File

@@ -0,0 +1,52 @@
/**
* @license
* Copyright 2025 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
/**
* Sanitize hook name to remove potentially sensitive information.
* Extracts the base command name without arguments or full paths.
*
* This function protects PII by removing:
* - Full file paths that may contain usernames
* - Command arguments that may contain credentials, API keys, tokens
* - Environment variables with sensitive values
*
* Examples:
* - "/path/to/.gemini/hooks/check-secrets.sh --api-key=abc123" -> "check-secrets.sh"
* - "python /home/user/script.py --token=xyz" -> "python"
* - "node index.js" -> "node"
* - "C:\\Windows\\System32\\cmd.exe /c secret.bat" -> "cmd.exe"
* - "" or " " -> "unknown-command"
*
* @param hookName Full command string.
* @returns Sanitized command name.
*/
export function sanitizeHookName(hookName: string): string {
// Handle empty or whitespace-only strings
if (!hookName || !hookName.trim()) {
return 'unknown-command';
}
// Split by spaces to get command parts
const parts = hookName.trim().split(/\s+/);
if (parts.length === 0) {
return 'unknown-command';
}
// Get the first part (the command)
const command = parts[0];
if (!command) {
return 'unknown-command';
}
// If it's a path, extract just the basename
if (command.includes('/') || command.includes('\\')) {
const pathParts = command.split(/[/\\]/);
const basename = pathParts[pathParts.length - 1];
return basename || 'unknown-command';
}
return command;
}

View File

@@ -38,6 +38,7 @@ import {
toOutputType,
toSystemInstruction,
} from './semantic.js';
import { sanitizeHookName } from './sanitize.js';
export interface BaseTelemetryEvent {
'event.name': string;
@@ -1737,3 +1738,86 @@ export class WebFetchFallbackAttemptEvent implements BaseTelemetryEvent {
return `Web fetch fallback attempt. Reason: ${this.reason}`;
}
}
export const EVENT_HOOK_CALL = 'gemini_cli.hook_call';
export class HookCallEvent implements BaseTelemetryEvent {
'event.name': string;
'event.timestamp': string;
hook_event_name: string;
hook_type: 'command';
hook_name: string;
hook_input: Record<string, unknown>;
hook_output?: Record<string, unknown>;
exit_code?: number;
stdout?: string;
stderr?: string;
duration_ms: number;
success: boolean;
error?: string;
constructor(
hookEventName: string,
hookType: 'command',
hookName: string,
hookInput: Record<string, unknown>,
durationMs: number,
success: boolean,
hookOutput?: Record<string, unknown>,
exitCode?: number,
stdout?: string,
stderr?: string,
error?: string,
) {
this['event.name'] = 'hook_call';
this['event.timestamp'] = new Date().toISOString();
this.hook_event_name = hookEventName;
this.hook_type = hookType;
this.hook_name = hookName;
this.hook_input = hookInput;
this.hook_output = hookOutput;
this.exit_code = exitCode;
this.stdout = stdout;
this.stderr = stderr;
this.duration_ms = durationMs;
this.success = success;
this.error = error;
}
toOpenTelemetryAttributes(config: Config): LogAttributes {
const attributes: LogAttributes = {
...getCommonAttributes(config),
'event.name': EVENT_HOOK_CALL,
'event.timestamp': this['event.timestamp'],
hook_event_name: this.hook_event_name,
hook_type: this.hook_type,
// Sanitize hook_name unless full logging is enabled
hook_name: config.getTelemetryLogPromptsEnabled()
? this.hook_name
: sanitizeHookName(this.hook_name),
duration_ms: this.duration_ms,
success: this.success,
exit_code: this.exit_code,
};
// Only include potentially sensitive data if telemetry logging of prompts is enabled
if (config.getTelemetryLogPromptsEnabled()) {
attributes['hook_input'] = safeJsonStringify(this.hook_input, 2);
attributes['hook_output'] = safeJsonStringify(this.hook_output, 2);
attributes['stdout'] = this.stdout;
attributes['stderr'] = this.stderr;
}
if (this.error) {
// Always log errors
attributes['error'] = this.error;
}
return attributes;
}
toLogBody(): string {
const hookId = `${this.hook_event_name}.${this.hook_name}`;
const status = `${this.success ? 'succeeded' : 'failed'}`;
return `Hook call ${hookId} ${status} in ${this.duration_ms}ms`;
}
}