diff --git a/.gitignore b/.gitignore index 525d0eff..f2ccc1fa 100644 --- a/.gitignore +++ b/.gitignore @@ -69,3 +69,5 @@ workspaces/ .worktrees/ test-results/ artifacts/browser-profile-*/ +artifacts/idle-profile-*/ +artifacts/idle-*/ diff --git a/package.json b/package.json index 030fc1d0..89d6b7e6 100644 --- a/package.json +++ b/package.json @@ -81,7 +81,8 @@ "release:prepare": "bun run build && bun run type-check && bun run lint", "release:test": "./scripts/test-release-build.sh", "release:test:intel": "./scripts/test-release-build.sh x86_64", - "release:test:arm": "./scripts/test-release-build.sh aarch64" + "release:test:arm": "./scripts/test-release-build.sh aarch64", + "profile:idle": "node scripts/profile-idle.mjs" }, "dependencies": { "@base-ui/react": "^1.4.0", diff --git a/scripts/perf/cdp.mjs b/scripts/perf/cdp.mjs new file mode 100644 index 00000000..4be7886d --- /dev/null +++ b/scripts/perf/cdp.mjs @@ -0,0 +1,191 @@ +/** + * Shared Chrome DevTools Protocol helpers for OpenChamber performance tooling. + * + * `scripts/profile-browser.mjs` and `scripts/profile-idle.mjs` both drive Chrome + * over CDP. Launching, target discovery, and the minimal protocol client live + * here so both entry points stay thin and behave identically. + */ + +import { spawn } from "node:child_process" +import { createServer } from "node:net" +import { existsSync } from "node:fs" +import { platform } from "node:os" +import { join, resolve } from "node:path" +import process from "node:process" + +export const wait = (milliseconds) => new Promise((resolveWait) => setTimeout(resolveWait, milliseconds)) + +const chromeCandidates = () => { + if (platform() === "darwin") { + return [ + "/Applications/Google Chrome.app/Contents/MacOS/Google Chrome", + "/Applications/Google Chrome Canary.app/Contents/MacOS/Google Chrome Canary", + "/Applications/Chromium.app/Contents/MacOS/Chromium", + ] + } + if (platform() === "win32") { + return [ + join(process.env.PROGRAMFILES ?? "", "Google/Chrome/Application/chrome.exe"), + join(process.env["PROGRAMFILES(X86)"] ?? "", "Google/Chrome/Application/chrome.exe"), + join(process.env.LOCALAPPDATA ?? "", "Google/Chrome/Application/chrome.exe"), + ] + } + return ["/usr/bin/google-chrome", "/usr/bin/google-chrome-stable", "/usr/bin/chromium", "/usr/bin/chromium-browser"] +} + +export const resolveChrome = (explicit) => { + if (explicit) { + const candidate = resolve(explicit) + if (!existsSync(candidate)) throw new Error(`Chrome executable not found: ${candidate}`) + return candidate + } + const candidate = chromeCandidates().find((path) => path && existsSync(path)) + if (!candidate) throw new Error("Chrome/Chromium was not found. Pass its path with --chrome.") + return candidate +} + +export const reservePort = () => new Promise((resolvePort, reject) => { + const server = createServer() + server.unref() + server.on("error", reject) + server.listen(0, "127.0.0.1", () => { + const address = server.address() + if (!address || typeof address === "string") { + server.close() + reject(new Error("Could not reserve a Chrome debugging port")) + return + } + const port = address.port + server.close(() => resolvePort(port)) + }) +}) + +const waitForJson = async (url, timeoutMs = 15_000) => { + const deadline = Date.now() + timeoutMs + let lastError + while (Date.now() < deadline) { + try { + const response = await fetch(url) + if (response.ok) return await response.json() + } catch (error) { + lastError = error + } + await wait(100) + } + throw new Error(`Chrome debugging endpoint did not start: ${lastError?.message ?? url}`) +} + +export const createPageTarget = async (port) => { + const baseUrl = `http://127.0.0.1:${port}` + await waitForJson(`${baseUrl}/json/version`) + + try { + const response = await fetch(`${baseUrl}/json/new?${encodeURIComponent("about:blank")}`, { method: "PUT" }) + if (response.ok) { + const target = await response.json() + if (target?.type === "page" && target.webSocketDebuggerUrl) return target + } + } catch { + // Some Chromium variants do not expose /json/new; use their startup page. + } + + const targets = await waitForJson(`${baseUrl}/json`) + const target = targets.find((entry) => entry.type === "page" && entry.webSocketDebuggerUrl) + if (!target) throw new Error("Chrome did not expose or create a page target") + return target +} + +/** + * Chrome throttles timers and stops producing frames for windows it considers + * backgrounded or occluded. A profiling run must never silently measure a + * throttled renderer, so occlusion and background throttling are disabled for + * every launch: without these the idle report shows zero layouts per second + * regardless of how much work the page actually schedules. + */ +const ANTI_THROTTLING_ARGS = [ + "--disable-background-timer-throttling", + "--disable-backgrounding-occluded-windows", + "--disable-renderer-backgrounding", + "--disable-features=CalculateNativeWinOcclusion,IntensiveWakeUpThrottling", +] + +export const launchChrome = ({ chrome, profileDir, port, headless, extraArgs = [] }) => { + const args = [ + `--remote-debugging-port=${port}`, + `--user-data-dir=${profileDir}`, + "--no-first-run", + "--no-default-browser-check", + "--disable-background-networking", + ...ANTI_THROTTLING_ARGS, + ...extraArgs, + "about:blank", + ] + if (headless) args.unshift("--headless=new", "--disable-gpu") + return spawn(chrome, args, { stdio: "ignore" }) +} + +export class CdpClient { + constructor(url) { + this.socket = new WebSocket(url) + this.nextId = 1 + this.pending = new Map() + this.listeners = new Map() + } + + async connect() { + await new Promise((resolveConnect, reject) => { + this.socket.addEventListener("open", resolveConnect, { once: true }) + this.socket.addEventListener("error", reject, { once: true }) + }) + this.socket.addEventListener("message", (event) => { + const message = JSON.parse(String(event.data)) + if (message.id) { + const pending = this.pending.get(message.id) + if (!pending) return + this.pending.delete(message.id) + if (message.error) pending.reject(new Error(message.error.message)) + else pending.resolve(message.result ?? {}) + return + } + for (const listener of this.listeners.get(message.method) ?? []) listener(message.params ?? {}) + }) + } + + send(method, params = {}) { + const id = this.nextId++ + return new Promise((resolveSend, reject) => { + this.pending.set(id, { resolve: resolveSend, reject: reject }) + this.socket.send(JSON.stringify({ id, method, params })) + }) + } + + on(method, listener) { + const listeners = this.listeners.get(method) ?? new Set() + listeners.add(listener) + this.listeners.set(method, listeners) + return () => listeners.delete(listener) + } + + once(method, timeoutMs = 15_000) { + return new Promise((resolveEvent, reject) => { + const timeout = setTimeout(() => { + unsubscribe() + reject(new Error(`Timed out waiting for ${method}`)) + }, timeoutMs) + const unsubscribe = this.on(method, (params) => { + clearTimeout(timeout) + unsubscribe() + resolveEvent(params) + }) + }) + } + + close() { + this.socket.close() + } +} + +export const evaluateValue = async (client, expression) => { + const result = await client.send("Runtime.evaluate", { expression, returnByValue: true, awaitPromise: true }) + return result.result?.value ?? null +} diff --git a/scripts/perf/cpu-profile.mjs b/scripts/perf/cpu-profile.mjs new file mode 100644 index 00000000..6f96ae8a --- /dev/null +++ b/scripts/perf/cpu-profile.mjs @@ -0,0 +1,71 @@ +/** + * Aggregation helpers for `Profiler.stop()` CPU profiles. + * + * The sampling profiler answers "which functions burned the main thread while + * nobody touched the app", which is the question the idle report exists to + * answer. Self time is derived from the sample stream rather than from + * `hitCount`, because sample deltas carry the actual elapsed time. + */ + +const frameLabel = (callFrame) => { + const name = callFrame.functionName || "(anonymous)" + const url = callFrame.url || "(native)" + const shortUrl = url.replace(/^https?:\/\/[^/]+/, "") + return `${name} @ ${shortUrl}:${callFrame.lineNumber + 1}` +} + +/** + * @param {{nodes: Array, samples: Array, timeDeltas: Array}} profile + * @param {number} topCount + */ +export const summarizeCpuProfile = (profile, topCount = 25) => { + const nodes = new Map() + for (const node of profile?.nodes ?? []) nodes.set(node.id, node) + + const samples = profile?.samples ?? [] + const timeDeltas = profile?.timeDeltas ?? [] + + const selfMicros = new Map() + let totalMicros = 0 + let idleMicros = 0 + let gcMicros = 0 + let programMicros = 0 + + for (let index = 0; index < samples.length; index += 1) { + // `timeDeltas[i]` is the interval preceding sample `i`. + const delta = Math.max(0, Number(timeDeltas[index] ?? 0)) + totalMicros += delta + const node = nodes.get(samples[index]) + if (!node) continue + const name = node.callFrame?.functionName + if (name === "(idle)") { + idleMicros += delta + continue + } + if (name === "(garbage collector)") gcMicros += delta + if (name === "(program)") programMicros += delta + const label = frameLabel(node.callFrame ?? {}) + selfMicros.set(label, (selfMicros.get(label) ?? 0) + delta) + } + + const busyMicros = totalMicros - idleMicros + const toMs = (micros) => Number((micros / 1000).toFixed(2)) + + return { + sampleCount: samples.length, + totalMs: toMs(totalMicros), + idleMs: toMs(idleMicros), + busyMs: toMs(busyMicros), + busyPercent: totalMicros > 0 ? Number(((busyMicros / totalMicros) * 100).toFixed(2)) : 0, + garbageCollectorMs: toMs(gcMicros), + programMs: toMs(programMicros), + topSelfTime: [...selfMicros.entries()] + .sort((left, right) => right[1] - left[1]) + .slice(0, topCount) + .map(([label, micros]) => ({ + function: label, + selfMs: toMs(micros), + percentOfBusy: busyMicros > 0 ? Number(((micros / busyMicros) * 100).toFixed(2)) : 0, + })), + } +} diff --git a/scripts/perf/idle-probe.mjs b/scripts/perf/idle-probe.mjs new file mode 100644 index 00000000..0f11e829 --- /dev/null +++ b/scripts/perf/idle-probe.mjs @@ -0,0 +1,218 @@ +/** + * Page-side idle instrumentation. + * + * `buildIdleProbeSource()` returns a self-contained script installed with + * `Page.addScriptToEvaluateOnNewDocument`, so it wraps the scheduling APIs + * before any application module runs. The probe attributes wall time to the + * call site that scheduled the work, which is what identifies a background + * loop that keeps running while the user is idle. + * + * Design constraints: + * - The probe must not change observable behaviour: every wrapper forwards + * arguments and return values unchanged, and preserves handle identity so + * `clearInterval`/`cancelAnimationFrame` keep working. + * - Stack capture happens at schedule time, not at fire time, and stops after + * a bounded number of captures so instrumentation cannot become the + * bottleneck it is measuring. + */ + +export const IDLE_PROBE_GLOBAL = "__openchamberIdleProbe" + +const probeFactory = function installOpenchamberIdleProbe(globalName, stackCaptureBudget) { + if (globalThis[globalName]) return + + const now = () => performance.now() + const sites = new Map() + let stackCaptures = 0 + let recording = false + + const siteFromStack = (kind) => { + if (stackCaptures >= stackCaptureBudget) return `${kind} ` + stackCaptures += 1 + const stack = new Error().stack ?? "" + const lines = stack.split("\n") + for (const line of lines) { + // Skip the Error line and every frame belonging to the probe itself. + if (!line.includes("http")) continue + if (line.includes("installOpenchamberIdleProbe")) continue + const match = line.match(/\(?((?:https?:)\/\/[^\s)]+)\)?$/) + const location = match ? match[1] : line.trim() + const name = line.trim().replace(/^at\s+/, "").split(" (")[0] + return `${kind} ${name} @ ${location}` + } + return `${kind} ` + } + + const record = (site, elapsedMs) => { + if (!recording) return + let entry = sites.get(site) + if (!entry) { + entry = { site, calls: 0, totalMs: 0, maxMs: 0 } + sites.set(site, entry) + } + entry.calls += 1 + entry.totalMs += elapsedMs + if (elapsedMs > entry.maxMs) entry.maxMs = elapsedMs + } + + const counters = { + setTimeoutScheduled: 0, + setIntervalScheduled: 0, + rafScheduled: 0, + idleCallbackScheduled: 0, + listenersAdded: 0, + listenersRemoved: 0, + mutationRecords: 0, + resizeEntries: 0, + intersectionEntries: 0, + fetches: 0, + postMessages: 0, + } + const listenerTypes = new Map() + const bump = (map, key, amount) => map.set(key, (map.get(key) ?? 0) + amount) + + const wrapCallback = (callback, site) => { + if (typeof callback !== "function") return callback + return function instrumentedIdleProbeCallback(...args) { + const started = now() + try { + return callback.apply(this, args) + } finally { + record(site, now() - started) + } + } + } + + const nativeSetTimeout = globalThis.setTimeout + const nativeSetInterval = globalThis.setInterval + const nativeRaf = globalThis.requestAnimationFrame + const nativeIdle = globalThis.requestIdleCallback + + globalThis.setTimeout = function setTimeout(handler, timeout, ...rest) { + counters.setTimeoutScheduled += 1 + if (typeof handler !== "function") return nativeSetTimeout.call(this, handler, timeout, ...rest) + const site = siteFromStack(`setTimeout(${Number(timeout) || 0})`) + return nativeSetTimeout.call(this, wrapCallback(handler, site), timeout, ...rest) + } + + globalThis.setInterval = function setInterval(handler, timeout, ...rest) { + counters.setIntervalScheduled += 1 + if (typeof handler !== "function") return nativeSetInterval.call(this, handler, timeout, ...rest) + const site = siteFromStack(`setInterval(${Number(timeout) || 0})`) + return nativeSetInterval.call(this, wrapCallback(handler, site), timeout, ...rest) + } + + if (typeof nativeRaf === "function") { + globalThis.requestAnimationFrame = function requestAnimationFrame(callback) { + counters.rafScheduled += 1 + if (typeof callback !== "function") return nativeRaf.call(this, callback) + const site = siteFromStack("requestAnimationFrame") + return nativeRaf.call(this, wrapCallback(callback, site)) + } + } + + if (typeof nativeIdle === "function") { + globalThis.requestIdleCallback = function requestIdleCallback(callback, options) { + counters.idleCallbackScheduled += 1 + if (typeof callback !== "function") return nativeIdle.call(this, callback, options) + const site = siteFromStack("requestIdleCallback") + return nativeIdle.call(this, wrapCallback(callback, site), options) + } + } + + // Listener accounting explains the growing "JS event listeners" curve. + const nativeAdd = EventTarget.prototype.addEventListener + const nativeRemove = EventTarget.prototype.removeEventListener + EventTarget.prototype.addEventListener = function addEventListener(type, listener, options) { + counters.listenersAdded += 1 + bump(listenerTypes, String(type), 1) + return nativeAdd.call(this, type, listener, options) + } + EventTarget.prototype.removeEventListener = function removeEventListener(type, listener, options) { + counters.listenersRemoved += 1 + bump(listenerTypes, String(type), -1) + return nativeRemove.call(this, type, listener, options) + } + + const wrapObserver = (Original, kind, countEntries) => { + if (typeof Original !== "function") return Original + const Wrapped = function ObserverWrapper(callback, ...rest) { + const site = siteFromStack(kind) + const instrumented = typeof callback === "function" + ? function instrumentedObserverCallback(entries, observer) { + countEntries(entries) + const started = now() + try { + return callback.call(this, entries, observer) + } finally { + record(site, now() - started) + } + } + : callback + return new Original(instrumented, ...rest) + } + Wrapped.prototype = Original.prototype + return Wrapped + } + + globalThis.MutationObserver = wrapObserver(globalThis.MutationObserver, "MutationObserver", (entries) => { + counters.mutationRecords += entries?.length ?? 0 + }) + globalThis.ResizeObserver = wrapObserver(globalThis.ResizeObserver, "ResizeObserver", (entries) => { + counters.resizeEntries += entries?.length ?? 0 + }) + globalThis.IntersectionObserver = wrapObserver(globalThis.IntersectionObserver, "IntersectionObserver", (entries) => { + counters.intersectionEntries += entries?.length ?? 0 + }) + + const nativeFetch = globalThis.fetch + if (typeof nativeFetch === "function") { + globalThis.fetch = function fetch(...args) { + counters.fetches += 1 + return nativeFetch.apply(this, args) + } + } + + const nativePostMessage = globalThis.postMessage + if (typeof nativePostMessage === "function") { + globalThis.postMessage = function postMessage(...args) { + counters.postMessages += 1 + return nativePostMessage.apply(this, args) + } + } + + globalThis[globalName] = { + start() { + recording = true + sites.clear() + for (const key of Object.keys(counters)) counters[key] = 0 + }, + stop() { + recording = false + }, + snapshot() { + return { + stackCaptures, + stackBudgetExhausted: stackCaptures >= stackCaptureBudget, + counters: { ...counters }, + listenerTypes: [...listenerTypes.entries()] + .map(([type, net]) => ({ type, net })) + .filter((entry) => entry.net !== 0) + .sort((left, right) => right.net - left.net) + .slice(0, 25), + sites: [...sites.values()] + .sort((left, right) => right.totalMs - left.totalMs) + .slice(0, 40) + .map((entry) => ({ + site: entry.site, + calls: entry.calls, + totalMs: Number(entry.totalMs.toFixed(2)), + maxMs: Number(entry.maxMs.toFixed(2)), + })), + } + }, + } +} + +export const buildIdleProbeSource = (stackCaptureBudget = 200_000) => + `(${probeFactory.toString()})(${JSON.stringify(IDLE_PROBE_GLOBAL)}, ${stackCaptureBudget});` diff --git a/scripts/profile-idle.mjs b/scripts/profile-idle.mjs new file mode 100644 index 00000000..435c346c --- /dev/null +++ b/scripts/profile-idle.mjs @@ -0,0 +1,367 @@ +#!/usr/bin/env node +/** + * Fully automated idle CPU/memory capture for OpenChamber. + * + * Unlike `profile:browser`, this command needs no human in the loop: it loads + * the app, lets it settle, then records a window during which no input is + * delivered. Everything it reports is therefore work the app performs while the + * user is doing nothing, which is the regression class users notice as fan + * noise, battery drain, and a permanently busy tab. + * + * Reported dimensions (per second of the idle window): + * - main-thread busy time, script time, style recalculation, layout; + * - style recalculation and layout counts; + * - DOM node, document, frame, and JS event listener growth; + * - JS heap trajectory (start/end/max plus linear growth rate); + * - CPU sampling profile with self time per function; + * - scheduled-work attribution per timer/animation-frame/observer call site. + * + * Runs are directly comparable: `--baseline ` prints a per-metric + * delta table and exits non-zero when a budget in `--budget-*` is exceeded, so + * the same command works as an investigation tool and as a regression gate. + */ + +import { mkdir, readFile, writeFile } from "node:fs/promises" +import { homedir } from "node:os" +import { join, resolve } from "node:path" +import process from "node:process" + +import { CdpClient, createPageTarget, evaluateValue, launchChrome, reservePort, resolveChrome, wait } from "./perf/cdp.mjs" +import { buildIdleProbeSource, IDLE_PROBE_GLOBAL } from "./perf/idle-probe.mjs" +import { summarizeCpuProfile } from "./perf/cpu-profile.mjs" + +const HELP = `Usage: bun run profile:idle -- [options] + +Records what OpenChamber does while nobody is interacting with it. + +Options: + --url OpenChamber URL (default: http://localhost:3000) + --session Open this session before recording (deep link) + --tab Open this main tab before recording + --duration Idle recording window (default: 30) + --settle Wait after load before recording (default: 15) + --output Artifact directory (default: artifacts/idle-profile-