feat: Add OTEL log event gemini_cli.startup_stats for startup stats. (#14734)

packages/core/src/telemetry/loggers.ts

@@ -50,6 +50,7 @@ import type {
   ExtensionUpdateEvent,
   LlmLoopCheckEvent,
   HookCallEvent,
+  StartupStatsEvent,
 } from './types.js';
 import {
   recordApiErrorMetrics,
@@ -688,3 +689,17 @@ export function logHookCall(config: Config, event: HookCallEvent): void {
     );
   });
 }
+
+export function logStartupStats(
+  config: Config,
+  event: StartupStatsEvent,
+): void {
+  bufferTelemetryEvent(() => {
+    const logger = logs.getLogger(SERVICE_NAME);
+    const logRecord: LogRecord = {
+      body: event.toLogBody(),
+      attributes: event.toOpenTelemetryAttributes(config),
+    };
+    logger.emit(logRecord);
+  });
+}

packages/core/src/telemetry/startupProfiler.test.ts

@@ -13,6 +13,11 @@ vi.mock('./metrics.js', () => ({
   recordStartupPerformance: vi.fn(),
 }));
 
+// Mock loggers module
+vi.mock('./loggers.js', () => ({
+  logStartupStats: vi.fn(),
+}));
+
 // Mock os module
 vi.mock('node:os', () => ({
   platform: vi.fn(() => 'darwin'),
@@ -33,6 +38,7 @@ describe('StartupProfiler', () => {
   let profiler: StartupProfiler;
   let mockConfig: Config;
   let recordStartupPerformance: ReturnType<typeof vi.fn>;
+  let logStartupStats: ReturnType<typeof vi.fn>;
 
   beforeEach(async () => {
     vi.resetAllMocks();
@@ -42,6 +48,9 @@ describe('StartupProfiler', () => {
     recordStartupPerformance =
       metricsModule.recordStartupPerformance as ReturnType<typeof vi.fn>;
 
+    const loggersModule = await import('./loggers.js');
+    logStartupStats = loggersModule.logStartupStats as ReturnType<typeof vi.fn>;
+
     // Create a fresh profiler instance
     profiler = StartupProfiler.getInstance();
 
@@ -343,5 +352,28 @@ describe('StartupProfiler', () => {
         expect.objectContaining({ phase: 'complete_phase' }),
       );
     });
+    it('should log startup stats event', () => {
+      const handle = profiler.start('test_phase');
+      handle?.end();
+
+      profiler.flush(mockConfig);
+
+      expect(logStartupStats).toHaveBeenCalledWith(
+        mockConfig,
+        expect.objectContaining({
+          phases: expect.arrayContaining([
+            expect.objectContaining({
+              name: 'test_phase',
+              duration_ms: expect.any(Number),
+              start_time_usec: expect.any(Number),
+              end_time_usec: expect.any(Number),
+            }),
+          ]),
+          os_platform: 'darwin',
+          os_release: '22.6.0',
+          is_docker: false,
+        }),
+      );
+    });
   });
 });

packages/core/src/telemetry/startupProfiler.ts

@@ -10,6 +10,8 @@ import * as fs from 'node:fs';
 import type { Config } from '../config/config.js';
 import { recordStartupPerformance } from './metrics.js';
 import { debugLogger } from '../utils/debugLogger.js';
+import { StartupStatsEvent, type StartupPhaseStats } from './types.js';
+import { logStartupStats } from './loggers.js';
 
 interface StartupPhase {
   name: string;
@@ -197,6 +199,37 @@ export class StartupProfiler {
       }
     }
 
+    // Emit StartupStats event
+    const startupPhases: StartupPhaseStats[] = [];
+    for (const phase of this.phases.values()) {
+      if (!phase.ended) continue;
+      const measure = measures.find((m) => m.name === phase.name);
+      if (measure && phase.cpuUsage) {
+        startupPhases.push({
+          name: phase.name,
+          duration_ms: measure.duration,
+          cpu_usage_user_usec: phase.cpuUsage.user,
+          cpu_usage_system_usec: phase.cpuUsage.system,
+          start_time_usec: (performance.timeOrigin + measure.startTime) * 1000,
+          end_time_usec:
+            (performance.timeOrigin + measure.startTime + measure.duration) *
+            1000,
+        });
+      }
+    }
+
+    if (startupPhases.length > 0) {
+      logStartupStats(
+        config,
+        new StartupStatsEvent(
+          startupPhases,
+          os.platform(),
+          os.release(),
+          fs.existsSync('/.dockerenv'),
+        ),
+      );
+    }
+
     // Clear performance marks and measures for all tracked phases.
     for (const phaseName of this.phases.keys()) {
       const startMarkName = this.getStartMarkName(phaseName);

packages/core/src/telemetry/types.ts

@@ -1538,6 +1538,7 @@ export type TelemetryEvent =
   | AgentFinishEvent
   | RecoveryAttemptEvent
   | LlmLoopCheckEvent
+  | StartupStatsEvent
   | WebFetchFallbackAttemptEvent;
 
 export const EVENT_EXTENSION_DISABLE = 'gemini_cli.extension_disable';
@@ -1627,6 +1628,55 @@ export class SmartEditCorrectionEvent implements BaseTelemetryEvent {
   }
 }
 
+export interface StartupPhaseStats {
+  name: string;
+  duration_ms: number;
+  cpu_usage_user_usec: number;
+  cpu_usage_system_usec: number;
+  start_time_usec: number;
+  end_time_usec: number;
+}
+
+export const EVENT_STARTUP_STATS = 'gemini_cli.startup_stats';
+export class StartupStatsEvent implements BaseTelemetryEvent {
+  'event.name': 'startup_stats';
+  'event.timestamp': string;
+  phases: StartupPhaseStats[];
+  os_platform: string;
+  os_release: string;
+  is_docker: boolean;
+
+  constructor(
+    phases: StartupPhaseStats[],
+    os_platform: string,
+    os_release: string,
+    is_docker: boolean,
+  ) {
+    this['event.name'] = 'startup_stats';
+    this['event.timestamp'] = new Date().toISOString();
+    this.phases = phases;
+    this.os_platform = os_platform;
+    this.os_release = os_release;
+    this.is_docker = is_docker;
+  }
+
+  toOpenTelemetryAttributes(config: Config): LogAttributes {
+    return {
+      ...getCommonAttributes(config),
+      'event.name': EVENT_STARTUP_STATS,
+      'event.timestamp': this['event.timestamp'],
+      phases: JSON.stringify(this.phases),
+      os_platform: this.os_platform,
+      os_release: this.os_release,
+      is_docker: this.is_docker,
+    };
+  }
+
+  toLogBody(): string {
+    return `Startup stats: ${this.phases.length} phases recorded.`;
+  }
+}
+
 abstract class BaseAgentEvent implements BaseTelemetryEvent {
   abstract 'event.name':
     | 'agent_start'