From 37c74bb19d5a758e1b335fdeeae4c34f3efcbe09 Mon Sep 17 00:00:00 2001 From: can1357 Date: Thu, 5 Feb 2026 06:19:49 +0100 Subject: [PATCH] perf: migrated timing measurements to Bun.nanoseconds() for higher precision - Migrated timing measurements from `performance.now()` to `Bun.nanoseconds()` for higher precision benchmarking across all benchmark and timing-sensitive code. - Updated elapsed time calculations to convert nanoseconds to milliseconds using division by 1e6 to maintain consistent time units. - Increased benchmark precision from 4 to 6 decimal places for per-operation timing measurements. - Refactored grep benchmark to use averaged timing values instead of storing individual iteration times, reducing memory overhead. --- docs/porting-to-natives.md | 8 +-- packages/agent/test/agent-loop.test.ts | 8 +-- packages/ai/src/utils/event-stream.ts | 6 +-- packages/coding-agent/bench/rendering.ts | 6 +-- packages/coding-agent/src/tools/index.ts | 4 +- packages/natives/bench/grep.ts | 65 ++++++++++-------------- packages/tui/bench/kitty-sequence.ts | 6 +-- packages/tui/bench/parse-key.ts | 6 +-- packages/tui/bench/text-layout.ts | 6 +-- packages/tui/bench/width.ts | 4 +- scripts/trace-loader.ts | 4 +- 11 files changed, 56 insertions(+), 67 deletions(-) diff --git a/docs/porting-to-natives.md b/docs/porting-to-natives.md index b8db052f1..8f9230b85 100644 --- a/docs/porting-to-natives.md +++ b/docs/porting-to-natives.md @@ -56,7 +56,7 @@ Avoid ports that depend on JS-only state or dynamic imports. N-API exports shoul - Put benchmarks next to the owning package (`packages/tui/bench`, `packages/natives/bench`, or `packages/coding-agent/bench`). - Include a JS baseline and native version in the same run. -- Use `performance.now()` and a fixed iteration count. +- Use `Bun.nanoseconds()` and a fixed iteration count. - Keep the benchmark inputs small and realistic (actual data seen in the hot path). 5. **Build the native binary** @@ -125,10 +125,10 @@ Keep it simple and owned. `String`, `Vec`, and `Uint8Array` work. Avoid const ITERATIONS = 2000; function bench(name: string, fn: () => void): number { - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) fn(); - const elapsed = performance.now() - start; - console.log(`${name}: ${elapsed.toFixed(2)}ms total (${(elapsed / ITERATIONS).toFixed(4)}ms/op)`); + const elapsed = (Bun.nanoseconds() - start) / 1e6; + console.log(`${name}: ${elapsed.toFixed(2)}ms total (${(elapsed / ITERATIONS).toFixed(6)}ms/op)`); return elapsed; } diff --git a/packages/agent/test/agent-loop.test.ts b/packages/agent/test/agent-loop.test.ts index 96ee46eec..678bcfdf4 100644 --- a/packages/agent/test/agent-loop.test.ts +++ b/packages/agent/test/agent-loop.test.ts @@ -386,14 +386,14 @@ describe("agentLoop with AgentMessage", () => { parameters: toolSchema, async execute(_toolCallId, params) { if (params.value === "slow") { - startTimes.slow = performance.now(); + startTimes.slow = Bun.nanoseconds(); slowStartedResolve(); await slowContinue; - finishTimes.slow = performance.now(); + finishTimes.slow = Bun.nanoseconds(); } else { await slowStarted; - startTimes.fast = performance.now(); - finishTimes.fast = performance.now(); + startTimes.fast = Bun.nanoseconds(); + finishTimes.fast = Bun.nanoseconds(); fastFinishedResolve(); } return { diff --git a/packages/ai/src/utils/event-stream.ts b/packages/ai/src/utils/event-stream.ts index ed97d86f0..50cdd3f94 100644 --- a/packages/ai/src/utils/event-stream.ts +++ b/packages/ai/src/utils/event-stream.ts @@ -146,8 +146,8 @@ export class AssistantMessageEventStream extends EventStream= this.throttleMs) { // Flush immediately if throttle window has passed @@ -173,7 +173,7 @@ export class AssistantMessageEventStream extends EventStream void): number { - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { fn(); } - const elapsed = performance.now() - start; - const perOp = (elapsed / ITERATIONS).toFixed(4); + const elapsed = (Bun.nanoseconds() - start) / 1e6; + const perOp = (elapsed / ITERATIONS).toFixed(6); console.log(`${name}: ${elapsed.toFixed(2)}ms total (${perOp}ms/op)`); return elapsed; } diff --git a/packages/coding-agent/src/tools/index.ts b/packages/coding-agent/src/tools/index.ts index 46bb99953..4b1a276da 100644 --- a/packages/coding-agent/src/tools/index.ts +++ b/packages/coding-agent/src/tools/index.ts @@ -314,9 +314,9 @@ export async function createTools(session: ToolSession, toolNames?: string[]): P const slowTools: Array<{ name: string; ms: number }> = []; const results = await Promise.all( entries.map(async ([name, factory]) => { - const start = performance.now(); + const start = Bun.nanoseconds(); const tool = await factory(session); - const elapsed = performance.now() - start; + const elapsed = (Bun.nanoseconds() - start) / 1e6; if (elapsed > 5) { slowTools.push({ name, ms: Math.round(elapsed) }); } diff --git a/packages/natives/bench/grep.ts b/packages/natives/bench/grep.ts index f15a27dc5..a91331fc8 100644 --- a/packages/natives/bench/grep.ts +++ b/packages/natives/bench/grep.ts @@ -25,29 +25,7 @@ await grep({ pattern: "test", path: path.resolve(packages, "tui/src") }); console.log(`Benchmark: ${ITERATIONS} iterations per case\n`); for (const c of cases) { - // Main thread sequential - const mainTimes: number[] = []; - let mainMatches = 0; - for (let i = 0; i < ITERATIONS; i++) { - const start = performance.now(); - const result = await grep({ pattern: c.pattern, path: c.path, glob: c.glob }); - mainTimes.push(performance.now() - start); - mainMatches = result.totalMatches; - } - - // Main thread concurrent (8x parallel) - const mainConcurrentTimes: number[] = []; - for (let i = 0; i < ITERATIONS; i++) { - const start = performance.now(); - await Promise.all( - Array.from({ length: CONCURRENCY }, () => grep({ pattern: c.pattern, path: c.path, glob: c.glob })), - ); - mainConcurrentTimes.push(performance.now() - start); - } - - // Subprocess rg sequential - const rgTimes: number[] = []; - let rgMatches = 0; + const grepArgs = { pattern: c.pattern, path: c.path, glob: c.glob }; const rgDefaultArgs = ["--hidden", "--no-ignore", "--no-ignore-vcs"]; const globArg = c.glob ? ["-g", c.glob] : []; @@ -77,31 +55,42 @@ for (const c of cases) { return matches; }; + // Capture match counts from a single run + const mainMatches = (await grep(grepArgs)).totalMatches; + const rgMatches = countMatches(await runRg()); + + // Main thread sequential + let start = Bun.nanoseconds(); + for (let i = 0; i < ITERATIONS; i++) await grep(grepArgs); + const mainMs = (Bun.nanoseconds() - start) / 1e6 / ITERATIONS; + + // Main thread concurrent (8x parallel) + start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { - const start = performance.now(); - const result = await runRg(); - rgTimes.push(performance.now() - start); - rgMatches = countMatches(result); + await Promise.all(Array.from({ length: CONCURRENCY }, () => grep(grepArgs))); } + const mainConcurrentMs = (Bun.nanoseconds() - start) / 1e6 / ITERATIONS; + + // Subprocess rg sequential + start = Bun.nanoseconds(); + for (let i = 0; i < ITERATIONS; i++) await runRg(); + const rgMs = (Bun.nanoseconds() - start) / 1e6 / ITERATIONS; // Subprocess rg concurrent (8x parallel) - const rgConcurrentTimes: number[] = []; + start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { - const start = performance.now(); await Promise.all(Array.from({ length: CONCURRENCY }, () => runRg())); - rgConcurrentTimes.push(performance.now() - start); } - - const avg = (arr: number[]) => arr.reduce((a, b) => a + b, 0) / arr.length; + const rgConcurrentMs = (Bun.nanoseconds() - start) / 1e6 / ITERATIONS; console.log(`${c.name}:`); - console.log(` Main thread: ${avg(mainTimes).toFixed(2)}ms (${mainMatches} matches)`); - console.log(` Main thread 8x: ${avg(mainConcurrentTimes).toFixed(2)}ms`); - console.log(` Subprocess rg: ${avg(rgTimes).toFixed(2)}ms (${rgMatches} matches)`); - console.log(` Subprocess rg 8x: ${avg(rgConcurrentTimes).toFixed(2)}ms`); + console.log(` Main thread: ${mainMs.toFixed(2)}ms (${mainMatches} matches)`); + console.log(` Main thread 8x: ${mainConcurrentMs.toFixed(2)}ms`); + console.log(` Subprocess rg: ${rgMs.toFixed(2)}ms (${rgMatches} matches)`); + console.log(` Subprocess rg 8x: ${rgConcurrentMs.toFixed(2)}ms`); - const mainVsRg = avg(rgTimes) / avg(mainTimes); - const mainVsRgConcurrent = avg(rgConcurrentTimes) / avg(mainConcurrentTimes); + const mainVsRg = rgMs / mainMs; + const mainVsRgConcurrent = rgConcurrentMs / mainConcurrentMs; console.log( ` => Main thread is ${mainVsRg > 1 ? `${mainVsRg.toFixed(1)}x faster` : `${(1 / mainVsRg).toFixed(1)}x slower`} than rg (sequential)`, ); diff --git a/packages/tui/bench/kitty-sequence.ts b/packages/tui/bench/kitty-sequence.ts index a19833f51..7429181ef 100644 --- a/packages/tui/bench/kitty-sequence.ts +++ b/packages/tui/bench/kitty-sequence.ts @@ -25,12 +25,12 @@ function matchesKittySequenceJs(data: string, expectedCodepoint: number, expecte } function bench(name: string, fn: () => void): number { - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { fn(); } - const elapsed = performance.now() - start; - const perOp = (elapsed / ITERATIONS).toFixed(4); + const elapsed = (Bun.nanoseconds() - start) / 1e6; + const perOp = (elapsed / ITERATIONS).toFixed(6); console.log(`${name}: ${elapsed.toFixed(2)}ms total (${perOp}ms/op)`); return elapsed; } diff --git a/packages/tui/bench/parse-key.ts b/packages/tui/bench/parse-key.ts index 455ec1642..f8500b3f5 100644 --- a/packages/tui/bench/parse-key.ts +++ b/packages/tui/bench/parse-key.ts @@ -57,12 +57,12 @@ const samples = [ ]; function bench(name: string, fn: () => void): number { - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { fn(); } - const elapsed = performance.now() - start; - const perOp = (elapsed / ITERATIONS).toFixed(4); + const elapsed = (Bun.nanoseconds() - start) / 1e6; + const perOp = (elapsed / ITERATIONS).toFixed(6); console.log(`${name}: ${elapsed.toFixed(2)}ms total (${perOp}ms/op)`); return elapsed; } diff --git a/packages/tui/bench/text-layout.ts b/packages/tui/bench/text-layout.ts index 0fda246a6..da32f4ffe 100644 --- a/packages/tui/bench/text-layout.ts +++ b/packages/tui/bench/text-layout.ts @@ -14,12 +14,12 @@ const samples = { const wrapWidth = 40; function bench(name: string, fn: () => void): number { - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { fn(); } - const elapsed = performance.now() - start; - const perOp = (elapsed / ITERATIONS).toFixed(4); + const elapsed = (Bun.nanoseconds() - start) / 1e6; + const perOp = (elapsed / ITERATIONS).toFixed(6); console.log(`${name}: ${elapsed.toFixed(2)}ms total (${perOp}ms/op)`); return elapsed; } diff --git a/packages/tui/bench/width.ts b/packages/tui/bench/width.ts index be9b87f45..cf46510d3 100644 --- a/packages/tui/bench/width.ts +++ b/packages/tui/bench/width.ts @@ -70,11 +70,11 @@ function bench(name: string, fn: () => void): BenchResult { // Warmup for (let i = 0; i < WARMUP; i++) fn(); - const start = performance.now(); + const start = Bun.nanoseconds(); for (let i = 0; i < ITERATIONS; i++) { fn(); } - const totalMs = performance.now() - start; + const totalMs = (Bun.nanoseconds() - start) / 1e6; const perOpUs = (totalMs / ITERATIONS) * 1000; return { name, totalMs, perOpUs }; diff --git a/scripts/trace-loader.ts b/scripts/trace-loader.ts index 29dd9d6f8..57f5d79c6 100644 --- a/scripts/trace-loader.ts +++ b/scripts/trace-loader.ts @@ -3,7 +3,7 @@ * Usage: bun --preload ./scripts/trace-loader.ts