diff --git a/scripts/profile-coding-agent-node.mjs b/scripts/profile-coding-agent-node.mjs index c4c8c9053..44ccf86b6 100644 --- a/scripts/profile-coding-agent-node.mjs +++ b/scripts/profile-coding-agent-node.mjs @@ -215,6 +215,56 @@ function summarize(values) { }; } +function parseStartupTimings(stderr) { + const lines = stderr.split(/\r?\n/); + const timings = new Map(); + let inBlock = false; + + for (const line of lines) { + if (line.includes("--- Startup Timings ---")) { + inBlock = true; + continue; + } + if (!inBlock) { + continue; + } + if (line.includes("------------------------")) { + break; + } + const match = line.match(/^\s+([^:]+):\s+(\d+)ms$/); + if (!match) { + continue; + } + timings.set(match[1], Number.parseInt(match[2], 10)); + } + + return timings; +} + +function summarizeTimingMaps(runs) { + const valuesByLabel = new Map(); + for (const run of runs) { + for (const [label, value] of run.timings.entries()) { + const values = valuesByLabel.get(label); + if (values) { + values.push(value); + } else { + valuesByLabel.set(label, [value]); + } + } + } + + const summaries = new Map(); + for (const [label, values] of valuesByLabel.entries()) { + summaries.set(label, summarize(values)); + } + return summaries; +} + +function toMetricName(label) { + return `${label.replaceAll(/[^a-zA-Z0-9]+/g, "_").replaceAll(/^_+|_+$/g, "")}_ms`; +} + async function waitForExit(child, errorPrefix) { return await new Promise((resolve, reject) => { child.once("error", reject); @@ -362,7 +412,7 @@ async function runTuiBenchmarkRun({ runtime, runIndex, measuredIndex, options, p throw new Error(`CPU profile was not written: ${profilePath}`); } - return { elapsedMs, profilePath }; + return { elapsedMs, profilePath, timings: parseStartupTimings(stderr) }; } finally { if (tempRoot) { rmSync(tempRoot, { recursive: true, force: true }); @@ -464,7 +514,7 @@ async function runRpcBenchmarkRun({ runtime, runIndex, measuredIndex, options, p throw new Error(`CPU profile was not written: ${profilePath}`); } - return { elapsedMs: readyElapsedMs, profilePath }; + return { elapsedMs: readyElapsedMs, profilePath, timings: parseStartupTimings(stderr) }; } finally { if (tempRoot) { rmSync(tempRoot, { recursive: true, force: true }); @@ -541,16 +591,24 @@ async function main() { } const elapsedSummary = summarize(measuredRuns.map((run) => run.elapsedMs)); + const timingSummaries = summarizeTimingMaps(measuredRuns); const maxElapsedRun = measuredRuns.reduce((slowest, run) => (run.elapsedMs > slowest.elapsedMs ? run : slowest)); if (measuredRuns.length === 1) { process.stdout.write("\nResult\n"); process.stdout.write(` runtime: ${runtime}\n`); process.stdout.write(` mode: ${options.mode}\n`); process.stdout.write(` elapsed: ${formatMs(measuredRuns[0].elapsedMs)}\n`); + for (const [label, summary] of timingSummaries.entries()) { + process.stdout.write(` ${label}: ${formatMs(summary.median)}\n`); + } if (options.cpuProfile && maxElapsedRun.profilePath) { process.stdout.write(` selected profile: ${toDisplayPath(maxElapsedRun.profilePath)}\n`); process.stdout.write(` profiles dir: ${toDisplayPath(profileDir)}\n`); } + process.stdout.write(`METRIC startup_time_ms=${measuredRuns[0].elapsedMs.toFixed(1)}\n`); + for (const [label, summary] of timingSummaries.entries()) { + process.stdout.write(`METRIC ${toMetricName(label)}=${summary.median.toFixed(1)}\n`); + } return; } @@ -561,10 +619,17 @@ async function main() { process.stdout.write(` elapsed median: ${formatMs(elapsedSummary.median)}\n`); process.stdout.write(` elapsed avg: ${formatMs(elapsedSummary.avg)}\n`); process.stdout.write(` elapsed max: ${formatMs(elapsedSummary.max)}\n`); + for (const [label, summary] of timingSummaries.entries()) { + process.stdout.write(` ${label} median: ${formatMs(summary.median)}\n`); + } if (options.cpuProfile && maxElapsedRun.profilePath) { process.stdout.write(` selected profile: ${toDisplayPath(maxElapsedRun.profilePath)}\n`); process.stdout.write(` profiles dir: ${toDisplayPath(profileDir)}\n`); } + process.stdout.write(`METRIC startup_time_ms=${elapsedSummary.median.toFixed(1)}\n`); + for (const [label, summary] of timingSummaries.entries()) { + process.stdout.write(`METRIC ${toMetricName(label)}=${summary.median.toFixed(1)}\n`); + } } main().catch((error) => {