|
| 1 | +#!/usr/bin/env bun |
| 2 | +/** |
| 3 | + * Backend latency of CLOSING a native task pane, against REAL hosts (seq 1387). |
| 4 | + * |
| 5 | + * The sibling script `measure-native-pane-latency.ts` covers read/split/layout. This |
| 6 | + * one answers the question that one left open: where do the ~1.7 s of a pane close |
| 7 | + * actually go? It attributes every close to named phases instead of a single total: |
| 8 | + * |
| 9 | + * classify — the ownership verdict that gates signalling at all |
| 10 | + * handshake — connect + requestStop against the pane host |
| 11 | + * exitWait — the 100 ms registry poll until host + shell are observably gone |
| 12 | + * forceTerm — SIGTERM escalation, only when the handshake itself failed |
| 13 | + * forceKill — SIGKILL escalation, only when exitWait ran out |
| 14 | + * coordinator— the remainder of closeNativeTaskPane: layout reconcile + journal write |
| 15 | + * |
| 16 | + * Run: `bun run measure:native-pane-close` (JSON to stdout, progress to stderr). |
| 17 | + * Everything lands in a tmpdir, so `~/.dev3.0/` is never touched. |
| 18 | + */ |
| 19 | + |
| 20 | +import { mkdirSync, mkdtempSync, rmSync } from "node:fs"; |
| 21 | +import { tmpdir } from "node:os"; |
| 22 | +import { join } from "node:path"; |
| 23 | +import { NATIVE_MULTIPANE_DIR_ENV } from "../src/bun/native-terminal-multipane/paths"; |
| 24 | +import type { StopPhase } from "../src/bun/native-terminal-registry/registry"; |
| 25 | + |
| 26 | +/** Fixed id so repeated runs address the same deterministic session id. */ |
| 27 | +const TASK_ID = "00000000-0000-4000-8000-000000013870"; |
| 28 | +const REPS = Number(process.env.CLOSE_REPS) || 7; |
| 29 | + |
| 30 | +interface Stats { |
| 31 | + n: number; |
| 32 | + min: number; |
| 33 | + p50: number; |
| 34 | + p95: number; |
| 35 | + max: number; |
| 36 | +} |
| 37 | + |
| 38 | +function stats(samples: number[]): Stats { |
| 39 | + const sorted = [...samples].sort((a, b) => a - b); |
| 40 | + const at = (q: number): number => sorted[Math.min(sorted.length - 1, Math.floor(sorted.length * q))]!; |
| 41 | + const round = (value: number): number => Math.round(value * 10) / 10; |
| 42 | + return { |
| 43 | + n: sorted.length, |
| 44 | + min: round(sorted[0]!), |
| 45 | + p50: round(at(0.5)), |
| 46 | + p95: round(at(0.95)), |
| 47 | + max: round(sorted[sorted.length - 1]!), |
| 48 | + }; |
| 49 | +} |
| 50 | + |
| 51 | +function summarise(byPhase: Map<string, number[]>): Record<string, Stats> { |
| 52 | + const out: Record<string, Stats> = {}; |
| 53 | + for (const [name, samples] of [...byPhase].sort(([a], [b]) => a.localeCompare(b))) { |
| 54 | + if (samples.length) out[name] = stats(samples); |
| 55 | + } |
| 56 | + return out; |
| 57 | +} |
| 58 | + |
| 59 | +async function main(): Promise<void> { |
| 60 | + const root = mkdtempSync(join(tmpdir(), "dev3-native-pane-close-")); |
| 61 | + const work = join(root, "work"); |
| 62 | + mkdirSync(work, { recursive: true }); |
| 63 | + process.env.DEV3_NATIVE_SESSIONS_DIR = join(root, "native-sessions"); |
| 64 | + process.env[NATIVE_MULTIPANE_DIR_ENV] = join(root, "native-multipane"); |
| 65 | + process.env.DEV3_NATIVE_HOST_IMAGES_DIR = join(root, "host-images"); |
| 66 | + process.env.DEV3_LOG_DIR = join(root, "logs"); |
| 67 | + |
| 68 | + // Imported after the redirects: the path modules read these on first use. |
| 69 | + const panes = await import("../src/bun/native-task-panes"); |
| 70 | + const registry = await import("../src/bun/native-terminal-registry/registry"); |
| 71 | + const { paneSessionId } = await import("../src/bun/native-terminal-multipane/paths"); |
| 72 | + const { nativeTaskSessionId } = await import("../src/bun/task-terminal-backend"); |
| 73 | + const { defaultNativeShellLaunchSpec } = await import("../src/bun/native-terminal-registry/shell-launch"); |
| 74 | + |
| 75 | + const defaults = defaultNativeShellLaunchSpec({ platform: process.platform, cwd: work, env: process.env }); |
| 76 | + const launch = { executable: defaults.executable, argv: [...defaults.argv] }; |
| 77 | + const spawnOpts = { cwd: work, env: {}, launch }; |
| 78 | + |
| 79 | + const closeTotals: number[] = []; |
| 80 | + const stopTotals: number[] = []; |
| 81 | + const byPhase = new Map<string, number[]>(); |
| 82 | + const push = (name: string, ms: number): void => { |
| 83 | + const bucket = byPhase.get(name) ?? []; |
| 84 | + bucket.push(ms); |
| 85 | + byPhase.set(name, bucket); |
| 86 | + }; |
| 87 | + |
| 88 | + await panes.startNativeTaskPanes({ taskId: TASK_ID, cwd: work, env: {}, launch, cols: 120, rows: 40 }); |
| 89 | + |
| 90 | + try { |
| 91 | + for (let rep = 0; rep < REPS; rep++) { |
| 92 | + // Grow to two panes so the close reconciles a layout instead of tearing down. |
| 93 | + const before = (await panes.nativeTaskPanesState(TASK_ID))!; |
| 94 | + const created = await panes.splitNativeTaskPane(TASK_ID, before.panes[0]!.paneId, "vertical", spawnOpts); |
| 95 | + |
| 96 | + const mark = performance.now(); |
| 97 | + await panes.closeNativeTaskPane(TASK_ID, created.paneId); |
| 98 | + closeTotals.push(performance.now() - mark); |
| 99 | + console.error(` close rep=${rep + 1}/${REPS}`); |
| 100 | + } |
| 101 | + |
| 102 | + // Second pass: the same teardown one level down, so the registry phases are |
| 103 | + // attributed directly rather than inferred from the end-to-end total. |
| 104 | + for (let rep = 0; rep < REPS; rep++) { |
| 105 | + const before = (await panes.nativeTaskPanesState(TASK_ID))!; |
| 106 | + const created = await panes.splitNativeTaskPane(TASK_ID, before.panes[0]!.paneId, "vertical", spawnOpts); |
| 107 | + const sessionId = paneSessionId(nativeTaskSessionId(TASK_ID), created.paneId); |
| 108 | + |
| 109 | + const mark = performance.now(); |
| 110 | + await registry.stop(sessionId, { |
| 111 | + onPhase: (phase: StopPhase, ms: number) => push(phase, ms), |
| 112 | + }); |
| 113 | + stopTotals.push(performance.now() - mark); |
| 114 | + |
| 115 | + // Let the coordinator reconcile the now-dead pane out of the tree. |
| 116 | + await panes.closeNativeTaskPane(TASK_ID, created.paneId).catch(() => {}); |
| 117 | + console.error(` stop rep=${rep + 1}/${REPS}`); |
| 118 | + } |
| 119 | + |
| 120 | + const phases = summarise(byPhase); |
| 121 | + const closeStats = stats(closeTotals); |
| 122 | + const stopStats = stats(stopTotals); |
| 123 | + const phaseSum = Object.values(phases).reduce((acc, s) => acc + s.p50, 0); |
| 124 | + console.log( |
| 125 | + JSON.stringify( |
| 126 | + { |
| 127 | + platform: process.platform, |
| 128 | + bun: Bun.version, |
| 129 | + shell: launch.executable, |
| 130 | + closeEndToEnd: closeStats, |
| 131 | + registryStop: stopStats, |
| 132 | + phases, |
| 133 | + /** What closeNativeTaskPane costs on top of registry.stop, at p50. */ |
| 134 | + coordinatorOverheadP50Ms: Math.round((closeStats.p50 - stopStats.p50) * 10) / 10, |
| 135 | + phaseSumP50Ms: Math.round(phaseSum * 10) / 10, |
| 136 | + }, |
| 137 | + null, |
| 138 | + 2, |
| 139 | + ), |
| 140 | + ); |
| 141 | + } finally { |
| 142 | + await panes.stopNativeTaskPanes(TASK_ID).catch(() => {}); |
| 143 | + rmSync(root, { recursive: true, force: true }); |
| 144 | + } |
| 145 | + // The registry holds host sockets open; nothing else keeps this process useful. |
| 146 | + process.exit(0); |
| 147 | +} |
| 148 | + |
| 149 | +main().catch((err) => { |
| 150 | + console.error(err); |
| 151 | + process.exit(1); |
| 152 | +}); |
0 commit comments