feat(plan): create a metric for execution of plans generated in plan mode (#18236)

This commit is contained in:
Adib234
2026-02-05 18:46:34 -05:00
committed by GitHub
parent 83c6342e6e
commit 4ffc349c18
8 changed files with 173 additions and 2 deletions

View File

@@ -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.

View File

@@ -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(() => {

View File

@@ -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',

View File

@@ -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<string, never>,
},
[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
*/

View File

@@ -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;

View File

@@ -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 });

View File

@@ -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 {