diff --git a/docs/cli/telemetry.md b/docs/cli/telemetry.md index 9bf662b2a1..407ba101f2 100644 --- a/docs/cli/telemetry.md +++ b/docs/cli/telemetry.md @@ -320,6 +320,8 @@ Captures startup configuration and user prompt submissions. Tracks changes and duration of approval modes. +##### Lifecycle + - `approval_mode_switch`: Approval mode was changed. - **Attributes**: - `from_mode` (string) @@ -330,6 +332,15 @@ Tracks changes and duration of approval modes. - `mode` (string) - `duration_ms` (int) +##### Execution + +These events track the execution of an approval mode, such as Plan Mode. + +- `plan_execution`: A plan was executed and the session switched from plan mode + to active execution. + - **Attributes**: + - `approval_mode` (string) + #### Tools Captures tool executions, output truncation, and Edit behavior. @@ -710,6 +721,17 @@ Agent lifecycle metrics: runs, durations, and turns. - **Attributes**: - `agent_name` (string) +##### Approval Mode + +###### Execution + +These metrics track the adoption and usage of specific approval workflows, such +as Plan Mode. + +- `gemini_cli.plan.execution.count` (Counter, Int): Counts plan executions. + - **Attributes**: + - `approval_mode` (string) + ##### UI UI stability signals such as flicker count. diff --git a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts index d7c9656234..83fe62006e 100644 --- a/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts +++ b/packages/core/src/telemetry/clearcut-logger/clearcut-logger.ts @@ -45,6 +45,7 @@ import type { HookCallEvent, ApprovalModeSwitchEvent, ApprovalModeDurationEvent, + PlanExecutionEvent, } from '../types.js'; import { EventMetadataKey } from './event-metadata-key.js'; import type { Config } from '../../config/config.js'; @@ -106,6 +107,7 @@ export enum EventNames { HOOK_CALL = 'hook_call', APPROVAL_MODE_SWITCH = 'approval_mode_switch', APPROVAL_MODE_DURATION = 'approval_mode_duration', + PLAN_EXECUTION = 'plan_execution', } export interface LogResponse { @@ -1543,6 +1545,18 @@ export class ClearcutLogger { this.flushIfNeeded(); } + logPlanExecutionEvent(event: PlanExecutionEvent): void { + const data: EventValue[] = [ + { + gemini_cli_key: EventMetadataKey.GEMINI_CLI_APPROVAL_MODE, + value: event.approval_mode, + }, + ]; + + this.enqueueLogEvent(this.createLogEvent(EventNames.PLAN_EXECUTION, 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/loggers.ts b/packages/core/src/telemetry/loggers.ts index b20dac21b2..945e3a2f6b 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -55,6 +55,7 @@ import type { HookCallEvent, StartupStatsEvent, LlmLoopCheckEvent, + PlanExecutionEvent, } from './types.js'; import { recordApiErrorMetrics, @@ -73,6 +74,7 @@ import { recordRecoveryAttemptMetrics, recordLinesChanged, recordHookCallMetrics, + recordPlanExecution, } from './metrics.js'; import { bufferTelemetryEvent } from './sdk.js'; import type { UiEvent } from './uiTelemetry.js'; @@ -719,6 +721,20 @@ export function logApprovalModeDuration( }); } +export function logPlanExecution(config: Config, event: PlanExecutionEvent) { + ClearcutLogger.getInstance(config)?.logPlanExecutionEvent(event); + bufferTelemetryEvent(() => { + logs.getLogger(SERVICE_NAME).emit({ + body: event.toLogBody(), + attributes: event.toOpenTelemetryAttributes(config), + }); + + recordPlanExecution(config, { + approval_mode: event.approval_mode, + }); + }); +} + export function logHookCall(config: Config, event: HookCallEvent): void { ClearcutLogger.getInstance(config)?.logHookCallEvent(event); bufferTelemetryEvent(() => { diff --git a/packages/core/src/telemetry/metrics.test.ts b/packages/core/src/telemetry/metrics.test.ts index f1f7f2d223..b395674b28 100644 --- a/packages/core/src/telemetry/metrics.test.ts +++ b/packages/core/src/telemetry/metrics.test.ts @@ -96,6 +96,7 @@ describe('Telemetry Metrics', () => { let recordAgentRunMetricsModule: typeof import('./metrics.js').recordAgentRunMetrics; let recordLinesChangedModule: typeof import('./metrics.js').recordLinesChanged; let recordSlowRenderModule: typeof import('./metrics.js').recordSlowRender; + let recordPlanExecutionModule: typeof import('./metrics.js').recordPlanExecution; beforeEach(async () => { vi.resetModules(); @@ -140,6 +141,7 @@ describe('Telemetry Metrics', () => { recordAgentRunMetricsModule = metricsJsModule.recordAgentRunMetrics; recordLinesChangedModule = metricsJsModule.recordLinesChanged; recordSlowRenderModule = metricsJsModule.recordSlowRender; + recordPlanExecutionModule = metricsJsModule.recordPlanExecution; const otelApiModule = await import('@opentelemetry/api'); @@ -218,6 +220,29 @@ describe('Telemetry Metrics', () => { }); }); + describe('recordPlanExecution', () => { + it('does not record metrics if not initialized', () => { + const config = makeFakeConfig({}); + recordPlanExecutionModule(config, { approval_mode: 'default' }); + expect(mockCounterAddFn).not.toHaveBeenCalled(); + }); + + it('records a plan execution event when initialized', () => { + const config = makeFakeConfig({}); + initializeMetricsModule(config); + recordPlanExecutionModule(config, { approval_mode: 'autoEdit' }); + + // Called for session, then for plan execution + expect(mockCounterAddFn).toHaveBeenCalledTimes(2); + expect(mockCounterAddFn).toHaveBeenNthCalledWith(2, 1, { + 'session.id': 'test-session-id', + 'installation.id': 'test-installation-id', + 'user.email': 'test@example.com', + approval_mode: 'autoEdit', + }); + }); + }); + describe('initializeMetrics', () => { const mockConfig = { getSessionId: () => 'test-session-id', diff --git a/packages/core/src/telemetry/metrics.ts b/packages/core/src/telemetry/metrics.ts index 765a017559..c6da448f54 100644 --- a/packages/core/src/telemetry/metrics.ts +++ b/packages/core/src/telemetry/metrics.ts @@ -66,6 +66,7 @@ const BASELINE_COMPARISON = 'gemini_cli.performance.baseline.comparison'; const FLICKER_FRAME_COUNT = 'gemini_cli.ui.flicker.count'; const SLOW_RENDER_LATENCY = 'gemini_cli.ui.slow_render.latency'; const EXIT_FAIL_COUNT = 'gemini_cli.exit.fail.count'; +const PLAN_EXECUTION_COUNT = 'gemini_cli.plan.execution.count'; const baseMetricDefinition = { getCommonAttributes, @@ -205,6 +206,14 @@ const COUNTER_DEFINITIONS = { assign: (c: Counter) => (exitFailCounter = c), attributes: {} as Record, }, + [PLAN_EXECUTION_COUNT]: { + description: 'Counts plan executions (switching from Plan Mode).', + valueType: ValueType.INT, + assign: (c: Counter) => (planExecutionCounter = c), + attributes: {} as { + approval_mode: string; + }, + }, [EVENT_HOOK_CALL_COUNT]: { description: 'Counts hook calls, tagged by hook event name and success.', valueType: ValueType.INT, @@ -529,6 +538,7 @@ let agentRecoveryAttemptCounter: Counter | undefined; let agentRecoveryAttemptDurationHistogram: Histogram | undefined; let flickerFrameCounter: Counter | undefined; let exitFailCounter: Counter | undefined; +let planExecutionCounter: Counter | undefined; let slowRenderHistogram: Histogram | undefined; let hookCallCounter: Counter | undefined; let hookCallLatencyHistogram: Histogram | undefined; @@ -720,6 +730,20 @@ export function recordExitFail(config: Config): void { exitFailCounter.add(1, baseMetricDefinition.getCommonAttributes(config)); } +/** + * Records a metric for when a plan is executed. + */ +export function recordPlanExecution( + config: Config, + attributes: MetricDefinitions[typeof PLAN_EXECUTION_COUNT]['attributes'], +): void { + if (!planExecutionCounter || !isMetricsInitialized) return; + planExecutionCounter.add(1, { + ...baseMetricDefinition.getCommonAttributes(config), + ...attributes, + }); +} + /** * Records a metric for when a UI frame is slow in rendering */ diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index 2d98234ee3..e12b2847eb 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -1603,6 +1603,7 @@ export type TelemetryEvent = | StartupStatsEvent | WebFetchFallbackAttemptEvent | EditStrategyEvent + | PlanExecutionEvent | RewindEvent | EditCorrectionEvent; @@ -1894,12 +1895,17 @@ export class WebFetchFallbackAttemptEvent implements BaseTelemetryEvent { } export const EVENT_HOOK_CALL = 'gemini_cli.hook_call'; + +export const EVENT_APPROVAL_MODE_SWITCH = + 'gemini_cli.plan.approval_mode_switch'; export class ApprovalModeSwitchEvent implements BaseTelemetryEvent { eventName = 'approval_mode_switch'; from_mode: ApprovalMode; to_mode: ApprovalMode; constructor(fromMode: ApprovalMode, toMode: ApprovalMode) { + this['event.name'] = this.eventName; + this['event.timestamp'] = new Date().toISOString(); this.from_mode = fromMode; this.to_mode = toMode; } @@ -1909,7 +1915,7 @@ export class ApprovalModeSwitchEvent implements BaseTelemetryEvent { toOpenTelemetryAttributes(config: Config): LogAttributes { return { ...getCommonAttributes(config), - event_name: this.eventName, + event_name: EVENT_APPROVAL_MODE_SWITCH, from_mode: this.from_mode, to_mode: this.to_mode, }; @@ -1920,12 +1926,16 @@ export class ApprovalModeSwitchEvent implements BaseTelemetryEvent { } } +export const EVENT_APPROVAL_MODE_DURATION = + 'gemini_cli.plan.approval_mode_duration'; export class ApprovalModeDurationEvent implements BaseTelemetryEvent { eventName = 'approval_mode_duration'; mode: ApprovalMode; duration_ms: number; constructor(mode: ApprovalMode, durationMs: number) { + this['event.name'] = this.eventName; + this['event.timestamp'] = new Date().toISOString(); this.mode = mode; this.duration_ms = durationMs; } @@ -1935,7 +1945,7 @@ export class ApprovalModeDurationEvent implements BaseTelemetryEvent { toOpenTelemetryAttributes(config: Config): LogAttributes { return { ...getCommonAttributes(config), - event_name: this.eventName, + event_name: EVENT_APPROVAL_MODE_DURATION, mode: this.mode, duration_ms: this.duration_ms, }; @@ -1946,6 +1956,33 @@ export class ApprovalModeDurationEvent implements BaseTelemetryEvent { } } +export const EVENT_PLAN_EXECUTION = 'gemini_cli.plan.execution'; +export class PlanExecutionEvent implements BaseTelemetryEvent { + eventName = 'plan_execution'; + approval_mode: ApprovalMode; + + constructor(approvalMode: ApprovalMode) { + this['event.name'] = this.eventName; + this['event.timestamp'] = new Date().toISOString(); + this.approval_mode = approvalMode; + } + 'event.name': string; + 'event.timestamp': string; + + toOpenTelemetryAttributes(config: Config): LogAttributes { + return { + ...getCommonAttributes(config), + 'event.name': EVENT_PLAN_EXECUTION, + 'event.timestamp': this['event.timestamp'], + approval_mode: this.approval_mode, + }; + } + + toLogBody(): string { + return `Plan executed with approval mode: ${this.approval_mode}`; + } +} + export class HookCallEvent implements BaseTelemetryEvent { 'event.name': string; 'event.timestamp': string; diff --git a/packages/core/src/tools/exit-plan-mode.test.ts b/packages/core/src/tools/exit-plan-mode.test.ts index 1c6ad7d876..3e226c5142 100644 --- a/packages/core/src/tools/exit-plan-mode.test.ts +++ b/packages/core/src/tools/exit-plan-mode.test.ts @@ -15,6 +15,11 @@ import { ApprovalMode } from '../policy/types.js'; import * as fs from 'node:fs'; import os from 'node:os'; import { validatePlanPath } from '../utils/planUtils.js'; +import * as loggers from '../telemetry/loggers.js'; + +vi.mock('../telemetry/loggers.js', () => ({ + logPlanExecution: vi.fn(), +})); describe('ExitPlanModeTool', () => { let tool: ExitPlanModeTool; @@ -288,6 +293,30 @@ Ask the user for specific feedback on how to improve the plan.`, }); }); + it('should log plan execution event when plan is approved', async () => { + const planRelativePath = createPlanFile('test.md', '# Content'); + const invocation = tool.build({ plan_path: planRelativePath }); + + const confirmDetails = await invocation.shouldConfirmExecute( + new AbortController().signal, + ); + if (confirmDetails === false) return; + + await confirmDetails.onConfirm(ToolConfirmationOutcome.ProceedOnce, { + approved: true, + approvalMode: ApprovalMode.AUTO_EDIT, + }); + + await invocation.execute(new AbortController().signal); + + expect(loggers.logPlanExecution).toHaveBeenCalledWith( + mockConfig, + expect.objectContaining({ + approval_mode: ApprovalMode.AUTO_EDIT, + }), + ); + }); + it('should return cancellation message when cancelled', async () => { const planRelativePath = createPlanFile('test.md', '# Content'); const invocation = tool.build({ plan_path: planRelativePath }); diff --git a/packages/core/src/tools/exit-plan-mode.ts b/packages/core/src/tools/exit-plan-mode.ts index 3916eb79eb..ff2310bab0 100644 --- a/packages/core/src/tools/exit-plan-mode.ts +++ b/packages/core/src/tools/exit-plan-mode.ts @@ -22,6 +22,8 @@ import { validatePlanPath, validatePlanContent } from '../utils/planUtils.js'; import { ApprovalMode } from '../policy/types.js'; import { checkExhaustive } from '../utils/checks.js'; import { resolveToRealPath, isSubpath } from '../utils/paths.js'; +import { logPlanExecution } from '../telemetry/loggers.js'; +import { PlanExecutionEvent } from '../telemetry/types.js'; /** * Returns a human-readable description for an approval mode. @@ -226,6 +228,8 @@ export class ExitPlanModeInvocation extends BaseToolInvocation< this.config.setApprovalMode(newMode); this.config.setApprovedPlanPath(resolvedPlanPath); + logPlanExecution(this.config, new PlanExecutionEvent(newMode)); + const description = getApprovalModeDescription(newMode); return {