From 0d561fa49d1cf90491118400264aad2ad030c6cd Mon Sep 17 00:00:00 2001 From: Eric Date: Wed, 27 May 2026 10:19:53 -0700 Subject: [PATCH] [eric] perf: stopwatch the boot + headcount every file we ship --- frontend/src/shared/ws/WebSocketManager.ts | 13 ++ scripts/perf/README.md | 61 +++++++++ scripts/perf/file-count.js | 140 ++++++++++++++++++++ scripts/perf/parse-timing.js | 102 +++++++++++++++ scripts/perf/test-perf.js | 145 +++++++++++++++++++++ 5 files changed, 461 insertions(+) create mode 100644 scripts/perf/README.md create mode 100644 scripts/perf/file-count.js create mode 100644 scripts/perf/parse-timing.js create mode 100644 scripts/perf/test-perf.js diff --git a/frontend/src/shared/ws/WebSocketManager.ts b/frontend/src/shared/ws/WebSocketManager.ts index 667f3670..0b6a9f08 100644 --- a/frontend/src/shared/ws/WebSocketManager.ts +++ b/frontend/src/shared/ws/WebSocketManager.ts @@ -28,6 +28,11 @@ import { upsertOutput } from '../state/outputsSlice'; import { getAuthToken } from '../config'; import { notifyAgentCompletion } from '../notifications'; +// Phase 0 boot instrumentation: one-shot flag so we report the first streamed +// agent token to Electron main exactly once per app launch. Module scope (not +// instance) because multiple WebSocketManagers exist (one per session WS). +let firstAgentResponseMarked = false; + // Thin wrapper around getAuthToken so the connect() call site stays // synchronous. If the token isn't cached yet, returns '' and the WS // handshake will 4401 , onclose catches that and refreshes the token @@ -177,6 +182,14 @@ class WebSocketManager { // ONE React render per animation frame, so removing the pacing layer // doesn't reintroduce the parallel-agent re-render storm. private dispatchDelta(sessionId: string, messageId: string, delta: string) { + // Phase 0 boot instrumentation: the first streamed agent token is the + // "app is actually useful" milestone. Report it once to the Electron main + // process, which owns the timing log. Guarded by a module-level flag so + // this is a single no-op branch on every subsequent token. + if (!firstAgentResponseMarked) { + firstAgentResponseMarked = true; + try { (window as any).openswarm?.markFirstAgentResponse?.(); } catch { /* not in Electron */ } + } store.dispatch(streamDelta({ sessionId, messageId, delta })); } diff --git a/scripts/perf/README.md b/scripts/perf/README.md new file mode 100644 index 00000000..7e1d72d1 --- /dev/null +++ b/scripts/perf/README.md @@ -0,0 +1,61 @@ +# Boot + size instrumentation (Phase 0 baseline) + +Tooling to measure two things we used to guess at: how long a cold launch takes, +and how many files we make the OS (and Defender) scan. These numbers are the +baseline that Phase 6 (slimming) and Phase 7 (Squirrel vs NSIS) are judged against. + +## Boot timing + +`electron/main.js` emits four ordered milestones to `backend.log`, one line each: + +``` +[perf] app-launch t= +[perf] first-paint t= +[perf] backend-http-ready t= +[perf] first-agent-response t= +``` + +`t` is milliseconds since process start. `first-agent-response` is fired by the +renderer (`WebSocketManager.dispatchDelta`) on the first streamed agent token. + +Read and assert them after launching a packaged build: + +``` +node scripts/perf/parse-timing.js # human table, exits 1 if missing/unordered +node scripts/perf/parse-timing.js --json # machine-readable +node scripts/perf/parse-timing.js --log +``` + +backend.log lives next to `auth.token`: +- macOS: `~/Library/Application Support/OpenSwarm/data/backend.log` +- Windows: `%APPDATA%\OpenSwarm\data\backend.log` +- Linux: `~/.local/share/OpenSwarm/data/backend.log` + +## File count / size + +``` +node scripts/perf/file-count.js # auto-detects packaged tree +node scripts/perf/file-count.js --root # explicit +node scripts/perf/file-count.js --json +``` + +### Recorded baseline (Windows, win-unpacked/resources) + +| dir | files | size | +|-------------|--------|---------| +| python-env | 8421 | 373.6 MB | +| router | 2651 | 35.9 MB | +| backend | 86 | 8.2 MB | +| frontend | 11 | 232.3 MB | +| debugger | 75 | 1.2 MB | +| other | 3 | 621.3 MB | +| **TOTAL** | 11247 | 1.2 GB | + +`python-env` is by far the largest file count, so it dominates Defender's +per-file scan cost on first launch. That is the Phase 6a target. + +## Tests + +`node scripts/perf/test-perf.js` builds throwaway fixtures with known counts and +known timing logs, runs both tools against them, and asserts exact numbers plus +that the failure paths fail. Hermetic; needs no packaged build. 17 assertions. diff --git a/scripts/perf/file-count.js b/scripts/perf/file-count.js new file mode 100644 index 00000000..a30f92a0 --- /dev/null +++ b/scripts/perf/file-count.js @@ -0,0 +1,140 @@ +#!/usr/bin/env node +// Phase 0 baseline: walk the packaged output and report a per-directory file +// count and byte size for the heavy resource dirs we ship, plus a grand total. +// This is the number we measure Phase 6 (python-env/node_modules slimming) and +// Phase 7 (Squirrel vs NSIS) against, so it must be deterministic: same tree in +// => same numbers out, regardless of OS or which arch was packaged. +// +// Usage: +// node scripts/perf/file-count.js [--root ] [--json] +// +// With no --root it auto-detects the packaged resources dir for this platform, +// falling back to build-staging/ (the pre-package staging tree). Exits non-zero +// if it can't find anything to count so a CI gate notices a broken build. + +'use strict'; +const fs = require('fs'); +const path = require('path'); + +// Top-level resource dirs we care about. Anything else in the root is folded +// into "other" so the grand total always reconciles with a raw walk. +const DIRS_OF_INTEREST = ['python-env', 'node', 'node_modules', 'mcp-servers', 'backend', 'frontend', 'router', 'debugger']; + +function parseArgs(argv) { + const out = { root: null, json: false }; + for (let i = 0; i < argv.length; i++) { + if (argv[i] === '--root') out.root = argv[++i]; + else if (argv[i] === '--json') out.json = true; + } + return out; +} + +// Candidate locations for the packaged tree, most-specific first. We resolve +// relative to the repo root (two levels up from this file) so it works from any +// cwd. The mac .app Resources and the Windows win-unpacked/resources are the +// real shipped trees; build-staging is the pre-electron-builder snapshot. +function autodetectRoot(repoRoot) { + const dist = path.join(repoRoot, 'electron', 'dist'); + const candidates = [ + path.join(dist, 'win-unpacked', 'resources'), + path.join(dist, 'mac-arm64', 'OpenSwarm.app', 'Contents', 'Resources'), + path.join(dist, 'mac', 'OpenSwarm.app', 'Contents', 'Resources'), + path.join(dist, 'mac-universal', 'OpenSwarm.app', 'Contents', 'Resources'), + path.join(repoRoot, 'electron', 'build-staging'), + path.join(repoRoot, 'build-staging'), + ]; + return candidates.find((c) => safeIsDir(c)) || null; +} + +function safeIsDir(p) { + try { return fs.statSync(p).isDirectory(); } catch { return false; } +} + +// Recursive walk. Counts regular files (not directories), sums byte size. +// Symlinks are counted as files without following them, so a symlink loop can +// never hang the walk and the count stays deterministic. +function walk(dir) { + let files = 0; + let bytes = 0; + let entries; + try { entries = fs.readdirSync(dir, { withFileTypes: true }); } catch { return { files, bytes }; } + for (const ent of entries) { + const full = path.join(dir, ent.name); + if (ent.isDirectory()) { + const sub = walk(full); + files += sub.files; + bytes += sub.bytes; + } else { + files += 1; + try { bytes += fs.statSync(full).size; } catch { /* vanished mid-walk */ } + } + } + return { files, bytes }; +} + +function fmtBytes(n) { + const units = ['B', 'KB', 'MB', 'GB']; + let i = 0; + let v = n; + while (v >= 1024 && i < units.length - 1) { v /= 1024; i++; } + return `${v.toFixed(i === 0 ? 0 : 1)} ${units[i]}`; +} + +function main() { + const args = parseArgs(process.argv.slice(2)); + const repoRoot = path.resolve(__dirname, '..', '..'); + const root = args.root ? path.resolve(args.root) : autodetectRoot(repoRoot); + + if (!root || !safeIsDir(root)) { + process.stderr.write('file-count: no packaged tree found. Build first or pass --root.\n'); + process.exit(2); + } + + const report = { root, dirs: {}, total: { files: 0, bytes: 0 }, generatedAt: new Date().toISOString() }; + const topEntries = fs.readdirSync(root, { withFileTypes: true }); + const seen = new Set(); + + for (const name of DIRS_OF_INTEREST) { + const full = path.join(root, name); + if (safeIsDir(full)) { + report.dirs[name] = walk(full); + seen.add(name); + } else { + report.dirs[name] = { files: 0, bytes: 0, absent: true }; + } + } + + // "other" = everything in the root not already counted, so the printed total + // is the real total of the tree and can be cross-checked by an independent walk. + let other = { files: 0, bytes: 0 }; + for (const ent of topEntries) { + if (seen.has(ent.name)) continue; + const full = path.join(root, ent.name); + if (ent.isDirectory()) { const s = walk(full); other.files += s.files; other.bytes += s.bytes; } + else { other.files += 1; try { other.bytes += fs.statSync(full).size; } catch { /* gone */ } } + } + report.dirs.other = other; + + for (const k of Object.keys(report.dirs)) { + report.total.files += report.dirs[k].files; + report.total.bytes += report.dirs[k].bytes; + } + + if (args.json) { + process.stdout.write(JSON.stringify(report, null, 2) + '\n'); + return; + } + + process.stdout.write(`\nPackaged file count (root: ${root})\n`); + process.stdout.write(' ' + '-'.repeat(52) + '\n'); + const rows = Object.keys(report.dirs).sort((a, b) => report.dirs[b].files - report.dirs[a].files); + for (const name of rows) { + const d = report.dirs[name]; + const note = d.absent ? ' (absent)' : ''; + process.stdout.write(` ${name.padEnd(16)} ${String(d.files).padStart(8)} files ${fmtBytes(d.bytes).padStart(10)}${note}\n`); + } + process.stdout.write(' ' + '-'.repeat(52) + '\n'); + process.stdout.write(` ${'TOTAL'.padEnd(16)} ${String(report.total.files).padStart(8)} files ${fmtBytes(report.total.bytes).padStart(10)}\n\n`); +} + +main(); diff --git a/scripts/perf/parse-timing.js b/scripts/perf/parse-timing.js new file mode 100644 index 00000000..2a041726 --- /dev/null +++ b/scripts/perf/parse-timing.js @@ -0,0 +1,102 @@ +#!/usr/bin/env node +// Phase 0 baseline: parse the four boot milestones out of backend.log and prove +// they are present and correctly ordered. main.js emits one line per milestone: +// [perf] t= +// We read the most recent launch block (delimited by "===== launch ... =====") +// so a re-run measures the latest boot, not a stale one. +// +// Usage: +// node scripts/perf/parse-timing.js [--log ] [--json] +// +// Exit 0 if all four present and ordered, 1 otherwise. Designed to be the +// assertion step of the Phase 0 test: launch the packaged app, then run this. + +'use strict'; +const fs = require('fs'); +const os = require('os'); +const path = require('path'); + +// Canonical order. app-launch must be first and first-agent-response last; +// first-paint and backend-http-ready sit between and may swap (lazy backend +// paints the shell before Python answers, eager backend does the reverse), so +// we only require they fall between the bookends, not a fixed order vs each other. +const REQUIRED = ['app-launch', 'first-paint', 'backend-http-ready', 'first-agent-response']; + +function parseArgs(argv) { + const out = { log: null, json: false }; + for (let i = 0; i < argv.length; i++) { + if (argv[i] === '--log') out.log = argv[++i]; + else if (argv[i] === '--json') out.json = true; + } + return out; +} + +// Mirrors getAuthTokenFilePath()/getBackendLogPath() in electron/main.js. +function defaultLogPath() { + if (process.platform === 'darwin') { + return path.join(os.homedir(), 'Library', 'Application Support', 'OpenSwarm', 'data', 'backend.log'); + } else if (process.platform === 'win32') { + return path.join(process.env.APPDATA || os.homedir(), 'OpenSwarm', 'data', 'backend.log'); + } + const xdg = process.env.XDG_DATA_HOME || path.join(os.homedir(), '.local', 'share'); + return path.join(xdg, 'OpenSwarm', 'data', 'backend.log'); +} + +function fail(msg, report) { + if (report && report.json) { process.stdout.write(JSON.stringify({ ok: false, error: msg, ...report.data }, null, 2) + '\n'); } + else process.stderr.write(`FAIL: ${msg}\n`); + process.exit(1); +} + +function main() { + const args = parseArgs(process.argv.slice(2)); + const logPath = args.log ? path.resolve(args.log) : defaultLogPath(); + + let raw; + try { raw = fs.readFileSync(logPath, 'utf8'); } + catch { fail(`cannot read log at ${logPath} (launch the packaged app first)`, { json: args.json, data: { logPath } }); return; } + + // Take only the last launch block so we measure the most recent boot. + const marker = '===== launch'; + const lastIdx = raw.lastIndexOf(marker); + const block = lastIdx >= 0 ? raw.slice(lastIdx) : raw; + + const marks = {}; + const re = /\[perf\]\s+(\S+)\s+t=(\d+)/g; + let m; + while ((m = re.exec(block)) !== null) { + // First occurrence wins (matches main.js one-shot guard); ignore later dupes. + if (!(m[1] in marks)) marks[m[1]] = Number(m[2]); + } + + const report = { json: args.json, data: { logPath, marks } }; + const missing = REQUIRED.filter((k) => !(k in marks)); + if (missing.length) fail(`missing milestone(s): ${missing.join(', ')}`, report); + + // Bookends: app-launch earliest, first-agent-response latest. + const t = marks; + if (t['app-launch'] !== Math.min(...REQUIRED.map((k) => t[k]))) fail('app-launch is not the earliest milestone', report); + if (t['first-agent-response'] !== Math.max(...REQUIRED.map((k) => t[k]))) fail('first-agent-response is not the latest milestone', report); + for (const k of REQUIRED) if (!Number.isFinite(t[k]) || t[k] < 0) fail(`milestone ${k} has invalid t=${t[k]}`, report); + + const ordered = [...REQUIRED].sort((a, b) => t[a] - t[b]); + const result = { + ok: true, + logPath, + marks, + order: ordered.map((k) => `${k}@${t[k]}ms`), + durations: { + 'launch->first-paint': t['first-paint'] - t['app-launch'], + 'launch->backend-ready': t['backend-http-ready'] - t['app-launch'], + 'launch->first-agent-response': t['first-agent-response'] - t['app-launch'], + }, + }; + + if (args.json) { process.stdout.write(JSON.stringify(result, null, 2) + '\n'); return; } + process.stdout.write('\nPASS: all four boot milestones present and ordered.\n'); + process.stdout.write(` log: ${logPath}\n`); + for (const k of ordered) process.stdout.write(` ${k.padEnd(22)} ${String(t[k]).padStart(8)} ms\n`); + process.stdout.write(`\n launch -> first-agent-response: ${result.durations['launch->first-agent-response']} ms\n\n`); +} + +main(); diff --git a/scripts/perf/test-perf.js b/scripts/perf/test-perf.js new file mode 100644 index 00000000..e8fd932b --- /dev/null +++ b/scripts/perf/test-perf.js @@ -0,0 +1,145 @@ +#!/usr/bin/env node +// Phase 0 test: deterministic, hermetic checks of the perf tooling. Builds +// throwaway fixtures in a temp dir with KNOWN file counts and KNOWN timing +// logs, runs file-count.js and parse-timing.js against them, and asserts the +// numbers come back exactly right plus that the failure paths actually fail. +// No packaged build required, so this runs identically on Win, Mac, and CI. +// +// node scripts/perf/test-perf.js +// +// Exit 0 = all assertions passed. Any failure exits 1 with the first mismatch. + +'use strict'; +const fs = require('fs'); +const os = require('os'); +const path = require('path'); +const { execFileSync } = require('child_process'); + +const HERE = __dirname; +const NODE = process.execPath; +let passed = 0; + +function assert(cond, msg) { + if (!cond) { process.stderr.write(`\nASSERT FAILED: ${msg}\n`); process.exit(1); } + passed++; +} + +function mktmp(prefix) { + return fs.mkdtempSync(path.join(os.tmpdir(), prefix)); +} + +function writeFile(p, content) { + fs.mkdirSync(path.dirname(p), { recursive: true }); + fs.writeFileSync(p, content); +} + +// Runs a script, returns { code, stdout, stderr }. Never throws on non-zero. +function run(script, extraArgs) { + try { + const stdout = execFileSync(NODE, [path.join(HERE, script), ...extraArgs], { encoding: 'utf8' }); + return { code: 0, stdout, stderr: '' }; + } catch (e) { + return { code: e.status == null ? -1 : e.status, stdout: e.stdout || '', stderr: e.stderr || '' }; + } +} + +// ---- file-count.js ------------------------------------------------------- +function testFileCount() { + const root = mktmp('osw-fc-'); + // Known layout: python-env=3 files, node=2, node_modules=4, mcp-servers=1, + // plus a stray top-level file that must land in "other"=1. total=11. + writeFile(path.join(root, 'python-env', 'a.py'), 'x'); + writeFile(path.join(root, 'python-env', 'lib', 'b.py'), 'xx'); + writeFile(path.join(root, 'python-env', 'lib', 'c.so'), 'xxx'); + writeFile(path.join(root, 'node', 'x64', 'node.exe'), 'nn'); + writeFile(path.join(root, 'node', 'arm64', 'node'), 'nn'); + writeFile(path.join(root, 'node_modules', 'pkg', 'index.js'), 'a'); + writeFile(path.join(root, 'node_modules', 'pkg', 'readme.md'), 'a'); + writeFile(path.join(root, 'node_modules', 'dep', 'main.js'), 'a'); + writeFile(path.join(root, 'node_modules', 'dep', 'types.d.ts'), 'a'); + writeFile(path.join(root, 'mcp-servers', 'srv.js'), 'm'); + writeFile(path.join(root, 'app.asar'), 'stray'); + + const r = run('file-count.js', ['--root', root, '--json']); + assert(r.code === 0, `file-count exited ${r.code}: ${r.stderr}`); + const rep = JSON.parse(r.stdout); + assert(rep.dirs['python-env'].files === 3, `python-env files=${rep.dirs['python-env'].files} expected 3`); + assert(rep.dirs['node'].files === 2, `node files=${rep.dirs['node'].files} expected 2`); + assert(rep.dirs['node_modules'].files === 4, `node_modules files=${rep.dirs['node_modules'].files} expected 4`); + assert(rep.dirs['mcp-servers'].files === 1, `mcp-servers files=${rep.dirs['mcp-servers'].files} expected 1`); + assert(rep.dirs['other'].files === 1, `other files=${rep.dirs['other'].files} expected 1`); + assert(rep.total.files === 11, `total files=${rep.total.files} expected 11`); + + // Total must reconcile with an independent raw walk of the whole tree. + const independent = countRaw(root); + assert(rep.total.files === independent, `report total ${rep.total.files} != raw walk ${independent}`); + + // Missing root must exit non-zero (broken-build signal). + const bad = run('file-count.js', ['--root', path.join(root, 'does-not-exist'), '--json']); + assert(bad.code !== 0, 'file-count should exit non-zero for a missing root'); + + fs.rmSync(root, { recursive: true, force: true }); +} + +function countRaw(dir) { + let n = 0; + for (const ent of fs.readdirSync(dir, { withFileTypes: true })) { + if (ent.isDirectory()) n += countRaw(path.join(dir, ent.name)); + else n += 1; + } + return n; +} + +// ---- parse-timing.js ----------------------------------------------------- +function logBlock(marks) { + let s = `\n===== launch ${new Date().toISOString()} (app 1.1.69, win32/x64) =====\n`; + for (const [k, v] of Object.entries(marks)) s += `[perf] ${k} t=${v}\n`; + return s; +} + +function testParseTimingPass() { + const dir = mktmp('osw-pt-'); + const log = path.join(dir, 'backend.log'); + // Two launch blocks; the parser must read only the LAST. First block is + // deliberately broken (missing milestones) to prove staleness is ignored. + let content = logBlock({ 'app-launch': 5 }); + content += logBlock({ 'app-launch': 3, 'first-paint': 120, 'backend-http-ready': 800, 'first-agent-response': 2500 }); + fs.writeFileSync(log, content); + + const r = run('parse-timing.js', ['--log', log, '--json']); + assert(r.code === 0, `parse-timing should pass, exited ${r.code}: ${r.stderr}`); + const rep = JSON.parse(r.stdout); + assert(rep.ok === true, 'parse-timing ok should be true'); + assert(rep.marks['app-launch'] === 3, `read stale block: app-launch=${rep.marks['app-launch']} expected 3`); + assert(rep.durations['launch->first-agent-response'] === 2497, `duration=${rep.durations['launch->first-agent-response']} expected 2497`); + fs.rmSync(dir, { recursive: true, force: true }); +} + +function testParseTimingFailures() { + const dir = mktmp('osw-ptf-'); + + // (a) missing a milestone -> fail + const log1 = path.join(dir, 'missing.log'); + fs.writeFileSync(log1, logBlock({ 'app-launch': 0, 'first-paint': 10, 'backend-http-ready': 50 })); + assert(run('parse-timing.js', ['--log', log1]).code === 1, 'missing milestone should fail'); + + // (b) out of order: first-agent-response earlier than backend-ready -> fail + const log2 = path.join(dir, 'unordered.log'); + fs.writeFileSync(log2, logBlock({ 'app-launch': 0, 'first-paint': 10, 'backend-http-ready': 900, 'first-agent-response': 100 })); + assert(run('parse-timing.js', ['--log', log2]).code === 1, 'out-of-order should fail (first-agent-response not latest)'); + + // (c) app-launch not earliest -> fail + const log3 = path.join(dir, 'badlaunch.log'); + fs.writeFileSync(log3, logBlock({ 'app-launch': 50, 'first-paint': 10, 'backend-http-ready': 900, 'first-agent-response': 2000 })); + assert(run('parse-timing.js', ['--log', log3]).code === 1, 'app-launch-not-earliest should fail'); + + // (d) nonexistent log -> fail + assert(run('parse-timing.js', ['--log', path.join(dir, 'nope.log')]).code === 1, 'missing log file should fail'); + + fs.rmSync(dir, { recursive: true, force: true }); +} + +testFileCount(); +testParseTimingPass(); +testParseTimingFailures(); +process.stdout.write(`\nPhase 0 perf tooling: ${passed} assertions passed.\n`);