1  /**
  2   * Startup profiling utility for measuring and reporting time spent in various
  3   * initialization phases.
  4   *
  5   * Two modes:
  6   * 1. Sampled logging: 100% of ant users, 0.1% of external users - logs phases to Statsig
  7   * 2. Detailed profiling: CLAUDE_CODE_PROFILE_STARTUP=1 - full report with memory snapshots
  8   *
  9   * Uses Node.js built-in performance hooks API for standard timing measurement.
 10   */
 11  
 12  import { dirname, join } from 'path'
 13  import { getSessionId } from 'src/bootstrap/state.js'
 14  import {
 15    type AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
 16    logEvent,
 17  } from '../services/analytics/index.js'
 18  import { logForDebugging } from './debug.js'
 19  import { getClaudeConfigHomeDir, isEnvTruthy } from './envUtils.js'
 20  import { getFsImplementation } from './fsOperations.js'
 21  import { formatMs, formatTimelineLine, getPerformance } from './profilerBase.js'
 22  import { writeFileSync_DEPRECATED } from './slowOperations.js'
 23  
 24  // Module-level state - decided once at module load
 25  // eslint-disable-next-line custom-rules/no-process-env-top-level
 26  const DETAILED_PROFILING = isEnvTruthy(process.env.CLAUDE_CODE_PROFILE_STARTUP)
 27  
 28  // Sampling for Statsig logging: 100% ant, 0.5% external
 29  // Decision made once at startup - non-sampled users pay no profiling cost
 30  const STATSIG_SAMPLE_RATE = 0.005
 31  // eslint-disable-next-line custom-rules/no-process-env-top-level
 32  const STATSIG_LOGGING_SAMPLED =
 33    process.env.USER_TYPE === 'ant' || Math.random() < STATSIG_SAMPLE_RATE
 34  
 35  // Enable profiling if either detailed mode OR sampled for Statsig
 36  const SHOULD_PROFILE = DETAILED_PROFILING || STATSIG_LOGGING_SAMPLED
 37  
 38  // Track memory snapshots separately (perf_hooks doesn't track memory).
 39  // Only used when DETAILED_PROFILING is enabled.
 40  // Stored as an array that appends in the same order as perf.mark() calls, so
 41  // memorySnapshots[i] corresponds to getEntriesByType('mark')[i]. Using a Map
 42  // keyed by checkpoint name is wrong because some checkpoints fire more than
 43  // once (e.g. loadSettingsFromDisk_start fires during init and again after
 44  // plugins reset the settings cache), and the second call would overwrite the
 45  // first's memory snapshot.
 46  const memorySnapshots: NodeJS.MemoryUsage[] = []
 47  
 48  // Phase definitions for Statsig logging: [startCheckpoint, endCheckpoint]
 49  const PHASE_DEFINITIONS = {
 50    import_time: ['cli_entry', 'main_tsx_imports_loaded'],
 51    init_time: ['init_function_start', 'init_function_end'],
 52    settings_time: ['eagerLoadSettings_start', 'eagerLoadSettings_end'],
 53    total_time: ['cli_entry', 'main_after_run'],
 54  } as const
 55  
 56  // Record initial checkpoint if profiling is enabled
 57  if (SHOULD_PROFILE) {
 58    // eslint-disable-next-line custom-rules/no-top-level-side-effects
 59    profileCheckpoint('profiler_initialized')
 60  }
 61  
 62  /**
 63   * Record a checkpoint with the given name
 64   */
 65  export function profileCheckpoint(name: string): void {
 66    if (!SHOULD_PROFILE) return
 67  
 68    const perf = getPerformance()
 69    perf.mark(name)
 70  
 71    // Only capture memory when detailed profiling enabled (env var)
 72    if (DETAILED_PROFILING) {
 73      memorySnapshots.push(process.memoryUsage())
 74    }
 75  }
 76  
 77  /**
 78   * Get a formatted report of all checkpoints
 79   * Only available when DETAILED_PROFILING is enabled
 80   */
 81  function getReport(): string {
 82    if (!DETAILED_PROFILING) {
 83      return 'Startup profiling not enabled'
 84    }
 85  
 86    const perf = getPerformance()
 87    const marks = perf.getEntriesByType('mark')
 88    if (marks.length === 0) {
 89      return 'No profiling checkpoints recorded'
 90    }
 91  
 92    const lines: string[] = []
 93    lines.push('='.repeat(80))
 94    lines.push('STARTUP PROFILING REPORT')
 95    lines.push('='.repeat(80))
 96    lines.push('')
 97  
 98    let prevTime = 0
 99    for (const [i, mark] of marks.entries()) {
100      lines.push(
101        formatTimelineLine(
102          mark.startTime,
103          mark.startTime - prevTime,
104          mark.name,
105          memorySnapshots[i],
106          8,
107          7,
108        ),
109      )
110      prevTime = mark.startTime
111    }
112  
113    const lastMark = marks[marks.length - 1]
114    lines.push('')
115    lines.push(`Total startup time: ${formatMs(lastMark?.startTime ?? 0)}ms`)
116    lines.push('='.repeat(80))
117  
118    return lines.join('\n')
119  }
120  
121  let reported = false
122  
123  export function profileReport(): void {
124    if (reported) return
125    reported = true
126  
127    // Log to Statsig (sampled: 100% ant, 0.1% external)
128    logStartupPerf()
129  
130    // Output detailed report if CLAUDE_CODE_PROFILE_STARTUP=1
131    if (DETAILED_PROFILING) {
132      // Write to file
133      const path = getStartupPerfLogPath()
134      const dir = dirname(path)
135      const fs = getFsImplementation()
136      fs.mkdirSync(dir)
137      writeFileSync_DEPRECATED(path, getReport(), {
138        encoding: 'utf8',
139        flush: true,
140      })
141  
142      logForDebugging('Startup profiling report:')
143      logForDebugging(getReport())
144    }
145  }
146  
147  export function isDetailedProfilingEnabled(): boolean {
148    return DETAILED_PROFILING
149  }
150  
151  export function getStartupPerfLogPath(): string {
152    return join(getClaudeConfigHomeDir(), 'startup-perf', `${getSessionId()}.txt`)
153  }
154  
155  /**
156   * Log startup performance phases to Statsig.
157   * Only logs if this session was sampled at startup.
158   */
159  export function logStartupPerf(): void {
160    // Only log if we were sampled (decision made at module load)
161    if (!STATSIG_LOGGING_SAMPLED) return
162  
163    const perf = getPerformance()
164    const marks = perf.getEntriesByType('mark')
165    if (marks.length === 0) return
166  
167    // Build checkpoint lookup
168    const checkpointTimes = new Map<string, number>()
169    for (const mark of marks) {
170      checkpointTimes.set(mark.name, mark.startTime)
171    }
172  
173    // Compute phase durations
174    const metadata: Record<string, number | undefined> = {}
175  
176    for (const [phaseName, [startCheckpoint, endCheckpoint]] of Object.entries(
177      PHASE_DEFINITIONS,
178    )) {
179      const startTime = checkpointTimes.get(startCheckpoint)
180      const endTime = checkpointTimes.get(endCheckpoint)
181  
182      if (startTime !== undefined && endTime !== undefined) {
183        metadata[`${phaseName}_ms`] = Math.round(endTime - startTime)
184      }
185    }
186  
187    // Add checkpoint count for debugging
188    metadata.checkpoint_count = marks.length
189  
190    logEvent(
191      'tengu_startup_perf',
192      metadata as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
193    )
194  }