Swadhin Biswas feat: implement mervelas cli engine, built-in tools, and reactive UI · 4/3/2026
0358986
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
/**
* Query profiling utility for measuring and reporting time spent in the query
* pipeline from user input to first token arrival. Enable by setting CLAUDE_CODE_PROFILE_QUERY=1
*
* Uses Node.js built-in performance hooks API for standard timing measurement.
* Tracks each query session with detailed checkpoints for identifying bottlenecks.
*
* Checkpoints tracked (in order):
* - query_user_input_received: Start of profiling
* - query_context_loading_start/end: Loading system prompts and contexts
* - query_query_start: Entry to query call from REPL
* - query_fn_entry: Entry to query() function
* - query_microcompact_start/end: Microcompaction of messages
* - query_autocompact_start/end: Autocompaction check
* - query_setup_start/end: StreamingToolExecutor and model setup
* - query_api_loop_start: Start of API retry loop
* - query_api_streaming_start: Start of streaming API call
* - query_tool_schema_build_start/end: Building tool schemas
* - query_message_normalization_start/end: Normalizing messages
* - query_client_creation_start/end: Creating Anthropic client
* - query_api_request_sent: HTTP request dispatched (before await, inside retry body)
* - query_response_headers_received: .withResponse() resolved (headers arrived)
* - query_first_chunk_received: First streaming chunk received (TTFT)
* - query_api_streaming_end: Streaming complete
* - query_tool_execution_start/end: Tool execution
* - query_recursive_call: Before recursive query call
* - query_end: End of query
*/
import { join } from 'path'
import { getSessionId } from 'src/bootstrap/state.js'
import { logForDebugging } from './debug.js'
import { getClaudeConfigHomeDir, isEnvTruthy } from './envUtils.js'
import { getFsImplementation } from './fsOperations.js'
import { formatMs, formatTimelineLine, getPerformance } from './profilerBase.js'
import { writeFileSync_DEPRECATED } from './slowOperations.js'
// Module-level state - initialized once when the module loads
// eslint-disable-next-line custom-rules/no-process-env-top-level
const ENABLED = isEnvTruthy(process.env.CLAUDE_CODE_PROFILE_QUERY)
// Track memory snapshots separately (perf_hooks doesn't track memory)
const memorySnapshots = new Map<string, NodeJS.MemoryUsage>()
// Track query count for reporting
let queryCount = 0
// Track first token received time separately for summary
let firstTokenTime: number | null = null
/**
* Start profiling a new query session
*/
export function startQueryProfile(): void {
if (!ENABLED) return
const perf = getPerformance()
// Clear previous marks and memory snapshots
perf.clearMarks()
memorySnapshots.clear()
firstTokenTime = null
queryCount++
// Record the start checkpoint
queryCheckpoint('query_user_input_received')
}
/**
* Record a checkpoint with the given name
*/
export function queryCheckpoint(name: string): void {
if (!ENABLED) return
const perf = getPerformance()
perf.mark(name)
memorySnapshots.set(name, process.memoryUsage())
// Track first token specially
if (name === 'query_first_chunk_received' && firstTokenTime === null) {
const marks = perf.getEntriesByType('mark')
if (marks.length > 0) {
const lastMark = marks[marks.length - 1]
firstTokenTime = lastMark?.startTime ?? 0
}
}
}
/**
* End the current query profiling session
*/
export function endQueryProfile(): void {
if (!ENABLED) return
queryCheckpoint('query_profile_end')
}
/**
* Identify slow operations (> 100ms delta)
*/
function getSlowWarning(deltaMs: number, name: string): string {
// Don't flag the first checkpoint as slow - it measures time from process start,
// not actual processing overhead
if (name === 'query_user_input_received') {
return ''
}
if (deltaMs > 1000) {
return ` ⚠️ VERY SLOW`
}
if (deltaMs > 100) {
return ` ⚠️ SLOW`
}
// Specific warnings for known bottlenecks
if (name.includes('git_status') && deltaMs > 50) {
return ' ⚠️ git status'
}
if (name.includes('tool_schema') && deltaMs > 50) {
return ' ⚠️ tool schemas'
}
if (name.includes('client_creation') && deltaMs > 50) {
return ' ⚠️ client creation'
}
return ''
}
/**
* Get a formatted report of all checkpoints for the current/last query
*/
function getQueryProfileReport(): string {
if (!ENABLED) {
return 'Query profiling not enabled (set CLAUDE_CODE_PROFILE_QUERY=1)'
}
const perf = getPerformance()
const marks = perf.getEntriesByType('mark')
if (marks.length === 0) {
return 'No query profiling checkpoints recorded'
}
const lines: string[] = []
lines.push('='.repeat(80))
lines.push(`QUERY PROFILING REPORT - Query #${queryCount}`)
lines.push('='.repeat(80))
lines.push('')
// Use first mark as baseline (query start time) to show relative times
const baselineTime = marks[0]?.startTime ?? 0
let prevTime = baselineTime
let apiRequestSentTime = 0
let firstChunkTime = 0
for (const mark of marks) {
const relativeTime = mark.startTime - baselineTime
const deltaMs = mark.startTime - prevTime
lines.push(
formatTimelineLine(
relativeTime,
deltaMs,
mark.name,
memorySnapshots.get(mark.name),
10,
9,
getSlowWarning(deltaMs, mark.name),
),
)
// Track key milestones for summary (use relative times)
if (mark.name === 'query_api_request_sent') {
apiRequestSentTime = relativeTime
}
if (mark.name === 'query_first_chunk_received') {
firstChunkTime = relativeTime
}
prevTime = mark.startTime
}
// Calculate summary statistics (relative to baseline)
const lastMark = marks[marks.length - 1]
const totalTime = lastMark ? lastMark.startTime - baselineTime : 0
lines.push('')
lines.push('-'.repeat(80))
if (firstChunkTime > 0) {
const preRequestOverhead = apiRequestSentTime
const networkLatency = firstChunkTime - apiRequestSentTime
const preRequestPercent = (
(preRequestOverhead / firstChunkTime) *
100
).toFixed(1)
const networkPercent = ((networkLatency / firstChunkTime) * 100).toFixed(1)
lines.push(`Total TTFT: ${formatMs(firstChunkTime)}ms`)
lines.push(
` - Pre-request overhead: ${formatMs(preRequestOverhead)}ms (${preRequestPercent}%)`,
)
lines.push(
` - Network latency: ${formatMs(networkLatency)}ms (${networkPercent}%)`,
)
} else {
lines.push(`Total time: ${formatMs(totalTime)}ms`)
}
// Add phase summary
lines.push(getPhaseSummary(marks, baselineTime))
lines.push('='.repeat(80))
return lines.join('\n')
}
export function getQueryPerfLogPath(queryNumber = queryCount): string {
return join(
getClaudeConfigHomeDir(),
'query-perf',
`${getSessionId()}-q${queryNumber}.txt`,
)
}
/**
* Get phase-based summary showing time spent in each major phase
*/
function getPhaseSummary(
marks: Array<{ name: string; startTime: number }>,
baselineTime: number,
): string {
const phases: Array<{ name: string; start: string; end: string }> = [
{
name: 'Context loading',
start: 'query_context_loading_start',
end: 'query_context_loading_end',
},
{
name: 'Microcompact',
start: 'query_microcompact_start',
end: 'query_microcompact_end',
},
{
name: 'Autocompact',
start: 'query_autocompact_start',
end: 'query_autocompact_end',
},
{ name: 'Query setup', start: 'query_setup_start', end: 'query_setup_end' },
{
name: 'Tool schemas',
start: 'query_tool_schema_build_start',
end: 'query_tool_schema_build_end',
},
{
name: 'Message normalization',
start: 'query_message_normalization_start',
end: 'query_message_normalization_end',
},
{
name: 'Client creation',
start: 'query_client_creation_start',
end: 'query_client_creation_end',
},
{
name: 'Network TTFB',
start: 'query_api_request_sent',
end: 'query_first_chunk_received',
},
{
name: 'Tool execution',
start: 'query_tool_execution_start',
end: 'query_tool_execution_end',
},
]
const markMap = new Map(marks.map(m => [m.name, m.startTime - baselineTime]))
const lines: string[] = []
lines.push('')
lines.push('PHASE BREAKDOWN:')
for (const phase of phases) {
const startTime = markMap.get(phase.start)
const endTime = markMap.get(phase.end)
if (startTime !== undefined && endTime !== undefined) {
const duration = endTime - startTime
const bar = '█'.repeat(Math.min(Math.ceil(duration / 10), 50)) // 1 block per 10ms, max 50
lines.push(
` ${phase.name.padEnd(22)} ${formatMs(duration).padStart(10)}ms ${bar}`,
)
}
}
// Calculate pre-API overhead (everything before api_request_sent)
const apiRequestSent = markMap.get('query_api_request_sent')
if (apiRequestSent !== undefined) {
lines.push('')
lines.push(
` ${'Total pre-API overhead'.padEnd(22)} ${formatMs(apiRequestSent).padStart(10)}ms`,
)
}
return lines.join('\n')
}
/**
* Log the query profile report to debug output
*/
export function logQueryProfileReport(): void {
if (!ENABLED) return
const report = getQueryProfileReport()
logForDebugging(report)
try {
const path = getQueryPerfLogPath()
getFsImplementation().mkdirSync(join(getClaudeConfigHomeDir(), 'query-perf'))
writeFileSync_DEPRECATED(path, report, {
encoding: 'utf8',
flush: true,
})
} catch {
// Best-effort artifact write. Debug output above still preserves the report.
}
}