diff --git a/docs/perf/winv2/README.md b/docs/perf/winv2/README.md new file mode 100644 index 00000000..d74e3f3f --- /dev/null +++ b/docs/perf/winv2/README.md @@ -0,0 +1,173 @@ +# winv2: Windows startup + App Builder speed and bug fixes + +Branch: `eric/winv2`. Goal: profile the real Windows experience first, find the +biggest bottleneck before changing anything, then fix the two reported bugs and +make startup + first-app download feel instant. All numbers below are measured +on the **real installed packaged app** (Squirrel install at +`AppData/Local/openswarm`, latest `app-1.2.82`), Windows 11, not dev mode. + +Notion tracking (Todos DB): +- [Perf] Windows startup + download speed: backend cold-start is the bottleneck +- [App Builder] Windows preview broken: no bundled bash/npm + missing node_modules archive +- [Bug] Skills list empty until reboots + onboarding "Install a skill" step times out +- [Reliability] Distributed-systems hardening (design) + +## How these numbers were measured + +Source of truth: the packaged app's own perf markers in +`AppData/Roaming/openswarm/data/backend.log` (`[perf] app-launch`, +`[perf] first-paint`, `[perf] backend-http-ready`, written by `electron/main.js`). +These are wall-clock ms from process start, i.e. exactly what the user feels. +Raw extract: `baseline_startup.csv`. Re-run with `profile_startup.sh`. + +Import cost measured with the bundled interpreter: +`python-env/python.exe -X importtime -c "import backend.main"`. + +## Baseline (BEFORE any change) + +### Startup, per launch (ms) + +| metric | warm (typical) | cold (first run after each update) | +| --- | --- | --- | +| app-launch (electron ready) | 107-400 | 107-563 | +| first-paint (renderer) | 338-1205 | ~1200 | +| **backend-http-ready** | **8700-10500** | **54600 / 81000 / 86300 / 133000 / 138300** | + +Electron shell paints in well under 1.5s every time. The Python backend is the +whole story: ~9-10s warm, and **54-138 seconds** on a cold/post-update launch. +First-agent-response figures in the log are dominated by user think-time and are +not treated as a startup metric. + +### Why the backend is slow (evidence) + +| factor | measurement | effect | +| --- | --- | --- | +| python-env file count | 13,554 files (4,510 .py/.pyd/.dll), 484 MB | Windows Defender real-time scan of every file on the first run after each update = the 1-2 minute cold spikes | +| app.asar size | 639 MB | cold disk read on first launch | +| backend.main import tree | ~2.2 s warm (`-X importtime`) | floor on warm boot, before interpreter init + lifespans | +| debugger project scan | runs at import (DEBUGLETON / build_structure) | extra warm boot time on the critical path | +| SubApp lifespans | entered sequentially in `config/Apps.py` before HTTP bind | serialized startup I/O | + +## Bottleneck ranking (before changes) + +1. **Python backend cold-start (dominant).** 9-10s warm, 54-138s cold. ~95% of + perceived startup. Cold case driven by Defender scanning 13.5k files + the + 639 MB asar; warm case by import tree + debugger scan + serial lifespans. +2. **App Builder first-app on Windows is fully broken** (Bug #2): no bundled + bash, bundled node has no npm, and the Windows build ships no node_modules + archive. Confirmed against the installed binary. Until fixed, "download time" + for an app is effectively infinite (it never succeeds on a clean machine). +3. **Skills registry network race** (Bug #1): empty catalog until reboot, breaks + the onboarding "Install a skill" step (15s selector timeout). + +## Plan (status tracked here + on Notion) + +- [~] Bug #2 App Builder: **junction/copy link fallback DONE + tested**; archive in Windows build + direct vite spawn (no bash) TODO +- [~] Bug #1 Skills: **bundled snapshot + disk cache + retry-until-success DONE + tested** (catalog never empty offline, onboarding pdf selector resolves); frontend loading-vs-empty retry TODO +- [ ] Perf: trim Defender surface, lazy imports, non-blocking lifespans, move debugger scan off boot, App Builder warm pool +- [ ] Re-measure, before/after tables + graphs + +## Progress log + +- 2026-06-16 baseline measured (this doc), graphs generated, Notion todos opened. +- 2026-06-16 Bug #1 backend: `skill_registry.py` now seeds from bundled `skills_snapshot.json` + on-disk last-good cache and retries until first success. Proven non-empty fully offline (17 skills, search+stats green); `pdf` skill present so onboarding `skill-item-pdf` resolves. Regression test `backend/tests/test_skill_registry_seed.py` (3 cases green). +- 2026-06-16 Bug #2 link: `_link_node_modules` now falls back symlink -> junction (`mklink /J`, no admin) -> copy, so node_modules links even on a locked-down Windows box. Tested with forced symlink failure. + +## Results (AFTER) + +### The warm-startup bottleneck was found and fixed + +Per-SubApp-lifespan profiling (`profile_boot.py`) showed the entire ~8s gap was +**one lifespan**: + +| boot phase | before | after | note | +| --- | --- | --- | --- | +| import backend.main | 798 ms | 764 ms | unchanged (debugger scan is only ~80 ms) | +| **service lifespan** | **7412 ms** | **84 ms** | was `await ensure_9router()` blocking the HTTP bind | +| other 15 lifespans | 45 ms | 9 ms | all trivial | +| **import + lifespans floor** | **8256 ms** | **857 ms** | ~7.4 s removed (~90%) | + +Fix: `service.py` now starts 9Router in the **background** instead of awaiting it +on the boot path. 9Router is only needed when the user sends an agent message, +and the dispatch path already calls `ensure_running()` (now lock-serialized in +`process.py` so the background start and a dispatch-time ensure can't +double-spawn). Net: warm backend-http-ready should drop from ~9-10 s to ~2-3 s, +comfortably under the 10 s goal. See `boot_breakdown.svg`. + +### Still open (cold start) + +The 54-138 s cold spikes are Windows Defender scanning the 13,554-file / 484 MB +python-env on the first run after each update, plus cold-reading the 639 MB +asar. That is a packaging change (fewer/larger files, trusted-location, or +zipped stdlib) and is higher-risk, tracked separately. The 9Router backgrounding +also helps cold (it no longer compounds the Defender wait). + +### App Builder first-app "download" + create path (measured) + +Per-phase, measured on this Windows box (`measure_appbuilder.py` + `measure_vite.py`), +isolated temp dirs, real warm caches. See `appbuilder_breakdown.svg`. + +| phase | time | when it's paid | +| --- | --- | --- | +| seed workspace + link node_modules | 67 ms | every app (instant; junction/symlink to warm cache) | +| download: archive extract (new build path) | 14.2 s | once per machine/template version (Defender-bound: 215 MB nm) | +| download: npm install (cold fallback) | 42.7 s | once, only if no archive ships | +| vite bind: cold vite cache | 6.7 s | first app ever (esbuild pre-bundle) | +| vite bind: warm shared cache | 0.7 s | every subsequent app | +| build-time: tar nm -> archive | 6.8 s | on CI, never on the user's machine | + +**User-facing scenarios (create app -> live preview):** + +| scenario | total | notes | +| --- | --- | --- | +| first app, clean Windows, BEFORE fix | never works | `[WinError 2]` / "backend exited with code 1" (no bash/npm/archive) | +| first app, AFTER fix (tar archive) | ~21 s one-time | extract 14.2 + seed 0.07 + vite cold 6.7; and it actually works | +| **first app, AFTER fix + #9 item 2 (pre-extracted)** | **~7 s one-time (projected)** | **junction 0.07 + vite cold 6.7; the 14.2 s extract is gone** | +| first app, if we shipped npm instead | ~49 s | 42.7 + 6.7; the archive saves ~28 s and needs no npm | +| every subsequent app | ~0.8 s | seed 0.07 + vite warm 0.7 (near-instant) | + +#9 item 2 (DONE): the Windows build now ships node_modules ALREADY EXTRACTED in +resources (digest-tagged); `_ensure_warm_cache` junctions a workspace straight at +it (`_bundled_extracted_modules`), so there is no tar-extract on first app -- the +14.2 s Defender-scanned write cost moves to install time, once. Verified by +`backend/tests/test_bundled_extracted_modules.py` (selection + Mac fallback) and +the build step `build-app-win.ps1` 4b now robocopies the tree into resources. + +Takeaways: the archive (Bug #2 fix) turns a broken/∞ first-app into a working +~21s one-time, and ~0.8s for every app after. The remaining ~14s extract is the +SAME Defender-on-many-small-files cost as cold app-startup (Task #9) -- the one +lever that would shrink both. + +### Net time decreased per step (measured) + +| step | before | after | saved | +| --- | --- | --- | --- | +| backend boot: service lifespan | 7412 ms | 84 ms | -7328 ms (-99%) | +| backend boot: import + all lifespans floor | 8256 ms | 857 ms | -7399 ms (-90%) | +| backend-http-ready warm (end-to-end) | ~9-10 s | ~2-3 s (projected) | ~-7 s | +| App Builder dependency download | 42.7 s npm | 14.2 s archive | -28.5 s (-67%) | +| App Builder first app -> preview | broken/never | ~21 s working | inf -> 21 s | +| App Builder subsequent app -> preview | n/a | ~0.8 s | near-instant | +| skills catalog availability | empty until reboot(s) | instant (seeded) | bug eliminated | + +## #9 packaging approach: shrink the Defender file surface (build-gated) + +Defender real-time-scans every small file: python-env = 13,554 files; node_modules += ~tens of thousands; app.asar = 639 MB. It rescans python-env on the first launch +after each update (54-138 s cold spikes) and scans node_modules as it is written +(the 14.2 s extract). Fix family: fewer/larger files, scan-once-at-install instead +of per-launch / per-first-app. Each item is independent, reversible, and must be +validated on a real packaged EXE (Task #10). + +1. [DRAFTED, build-gated] Zip the Python stdlib -> python313.zip (medium risk). Draft: scripts/zip-python-stdlib.ps1 (dry-run by default; NOT wired into the release build yet). Measured on the real env: 910 stdlib .py/.pyc files (15.1 MB) collapse into one zip. CPython auto-adds /python313.zip to sys.path, so no python._pth is needed; site-packages + DLLs (native .pyd) stay loose; a keep-list keeps data-file stdlib dirs (lib2to3, idlelib, tkinter, ...) loose. Impact: ~7% of total python-env file count, but it collapses the stdlib import-time file-opens (the cold-launch Defender scan storm) into a single scanned file; bigger combined with #3. Validation (Task #10): -Apply on a copy, then import backend.main, importtime parity, boot the packaged backend, measure cold backend-http-ready vs baseline. Wire into build-app-win.ps1 behind an off-by-default -ZipStdlib switch only after it passes. +2. [DONE] Ship webapp_template node_modules PRE-EXTRACTED in resources + junction to it (kills the 14.2 s extract -> ~0 s). build-app-win.ps1 step 4b robocopies the tree into resources; runtime _bundled_extracted_modules()/_ensure_warm_cache() prefer it; tests in test_bundled_extracted_modules.py. Mac still ships the .tar.gz (unchanged). +3. Precompile + ship only .pyc (drop .py) for app + pure-python deps. Halves remaining loose-file count; low risk; stacks with #1. +4. Inventory + trim app.asar (639 MB): source maps, dev-only deps, duplicate bundles. Single file (not a count issue) but shrinks cold-read I/O. +5. Opt-in Defender exclusion for install/data dirs, documented, never silent (needs admin/UAC; security-sensitive). Settings toggle only; do not auto-apply. + +Recommended order: #2 (biggest UX win, lowest risk), then #1 (largest cold win, careful import testing), then #3/#4. Validation: re-run profile_startup.sh + a fresh-extract timing on the packaged EXE after each change, diff vs baseline_startup.csv. + +### Bug fixes (this branch) + +- Bug #1 skills: seed from bundled snapshot + disk cache + retry-until-success. Catalog never empty offline; 3 tests green; onboarding `skill-item-pdf` resolves. +- Bug #2 App Builder: (a) `_link_node_modules` symlink->junction->copy fallback (tested); (b) Windows-only direct `vite` spawn via bundled node so frontend-only apps need no bash (kills `[WinError 2]`); (c) `build-app-win.ps1` now pre-builds the node_modules archive natively. Verified end to end on Windows: build digest == runtime `_warm_cache_digest` (`37335fdd1f4d`); the archive (26 MB) extracts to a working node_modules containing `vite/bin/vite.js` and the Windows-native `@esbuild/win32-x64/esbuild.exe`. diff --git a/docs/perf/winv2/appbuilder_breakdown.csv b/docs/perf/winv2/appbuilder_breakdown.csv new file mode 100644 index 00000000..4d8a4d9b --- /dev/null +++ b/docs/perf/winv2/appbuilder_breakdown.csv @@ -0,0 +1,7 @@ +phase,ms,note +"seed workspace + link node_modules (per app)",67,"nm linked, instant" +"download: archive extract (new build path, one-time)",14204,"215MB nm, defender-bound" +"download: npm install (cold fallback, one-time)",42684,"ok" +"vite bind: cold vite cache (first app)",6714,"bound" +"vite bind: warm shared cache (subsequent)",672,"bound" +"build-time: tar node_modules to archive (CI, not user)",6809,"26MB archive" diff --git a/docs/perf/winv2/appbuilder_breakdown.svg b/docs/perf/winv2/appbuilder_breakdown.svg new file mode 100644 index 00000000..0289a865 --- /dev/null +++ b/docs/perf/winv2/appbuilder_breakdown.svg @@ -0,0 +1,22 @@ + +App Builder "create app -> live preview" breakdown (ms) +seed workspace + link node_modules (per app) + +67ms +download: archive extract (new build path, one-time) + +14.20s +download: npm install (cold fallback, one-time) + +42.68s +vite bind: cold vite cache (first app) + +6.71s +vite bind: warm shared cache (subsequent) + +672ms +build-time: tar node_modules to archive (CI, not user) + +6.81s +green = warm/per-app cost; red = cold one-time download (npm with no archive) + \ No newline at end of file diff --git a/docs/perf/winv2/baseline_phases.svg b/docs/perf/winv2/baseline_phases.svg new file mode 100644 index 00000000..fc9ce33d --- /dev/null +++ b/docs/perf/winv2/baseline_phases.svg @@ -0,0 +1,12 @@ + +where startup time goes (backend dwarfs the shell) +typical warm launch + + +backend 9.6s (shell 0.68s) +typical cold launch + + +backend 86.3s (shell 1.48s) +dark = electron shell (app-launch + first-paint); colored = python backend + \ No newline at end of file diff --git a/docs/perf/winv2/baseline_startup.csv b/docs/perf/winv2/baseline_startup.csv new file mode 100644 index 00000000..70a803d0 --- /dev/null +++ b/docs/perf/winv2/baseline_startup.csv @@ -0,0 +1,15 @@ +launch_ts,version,app_launch_ms,first_paint_ms,backend_http_ready_ms,class +2026-06-02T09:18:13Z,1.1.72,380,1097,54606,cold +2026-06-08T22:16:53Z,1.2.73,143,636,10463,warm +2026-06-08T23:03:47Z,1.2.73,317,625,10084,warm +2026-06-08T23:58:30Z,1.2.73,198,515,81041,cold +2026-06-09T03:13:05Z,1.2.73,147,559,10418,warm +2026-06-09T11:04:12Z,1.2.75,129,609,10041,warm +2026-06-09T11:53:18Z,1.2.75,108,338,8761,warm +2026-06-10T07:44:10Z,1.2.75,388,1100,86310,cold +2026-06-10T07:46:53Z,1.2.76,112,389,9342,warm +2026-06-10T23:32:57Z,1.2.76,563,1205,133070,cold +2026-06-10T23:35:13Z,1.2.77,114,391,9349,warm +2026-06-10T23:35:41Z,1.2.77,122,404,9303,warm +2026-06-14T00:07:35Z,1.2.77,159,1213,138335,cold +2026-06-14T00:09:58Z,1.2.82,107,702,9590,warm diff --git a/docs/perf/winv2/baseline_startup.svg b/docs/perf/winv2/baseline_startup.svg new file mode 100644 index 00000000..14f09006 --- /dev/null +++ b/docs/perf/winv2/baseline_startup.svg @@ -0,0 +1,57 @@ + +backend-http-ready per launch (ms) - lower is better + +0s + +35s + +69s + +104s + +138s + +55s +1.1.72 + +10s +1.2.73 + +10s +1.2.73 + +81s +1.2.73 + +10s +1.2.73 + +10s +1.2.75 + +9s +1.2.75 + +86s +1.2.75 + +9s +1.2.76 + +133s +1.2.76 + +9s +1.2.77 + +9s +1.2.77 + +138s +1.2.77 + +10s +1.2.82 +warm +cold (post-update) + \ No newline at end of file diff --git a/docs/perf/winv2/boot_breakdown.csv b/docs/perf/winv2/boot_breakdown.csv new file mode 100644 index 00000000..025ec1f6 --- /dev/null +++ b/docs/perf/winv2/boot_breakdown.csv @@ -0,0 +1,5 @@ +phase,before_ms,after_ms +import backend.main,798,764 +service lifespan (9router start),7412,84 +other 15 lifespans,45,9 +import + lifespans floor,8256,857 diff --git a/docs/perf/winv2/boot_breakdown.svg b/docs/perf/winv2/boot_breakdown.svg new file mode 100644 index 00000000..4956f784 --- /dev/null +++ b/docs/perf/winv2/boot_breakdown.svg @@ -0,0 +1,31 @@ + +warm boot breakdown: before vs after (ms) - the service lifespan was the bottleneck + +0.0s + +4.1s + +8.3s + +0.8s + +0.8s +import backend.main + +7.4s + +0.1s +service lifespan (9router start) + +0.0s + +0.0s +other 15 lifespans + +8.3s + +0.9s +import + lifespans floor +before +after + \ No newline at end of file diff --git a/docs/perf/winv2/make_graphs.py b/docs/perf/winv2/make_graphs.py new file mode 100644 index 00000000..353527a6 --- /dev/null +++ b/docs/perf/winv2/make_graphs.py @@ -0,0 +1,190 @@ +"""Dependency-free SVG charts for the winv2 perf baseline. + +No matplotlib/pandas (not in the bundled env). Reads baseline_startup.csv and +writes two self-contained SVGs that render in a browser, GitHub, or Notion: + baseline_startup.svg - backend-http-ready per launch (warm vs cold) + baseline_phases.svg - where the time goes (app-launch / first-paint / backend) +Run: python make_graphs.py +""" +import csv +import os + +HERE = os.path.dirname(os.path.abspath(__file__)) +CSV = os.path.join(HERE, "baseline_startup.csv") + +WARM = "#2e9e5b" +COLD = "#d64545" +INK = "#1a1d27" +MUTE = "#8892a4" +GRID = "#e2e6ef" + + +def rows(): + with open(CSV, newline="", encoding="utf-8") as f: + return list(csv.DictReader(f)) + + +def bars_chart(data): + w, h = 900, 420 + pad_l, pad_b, pad_t, pad_r = 60, 90, 50, 20 + plot_w = w - pad_l - pad_r + plot_h = h - pad_t - pad_b + vals = [int(r["backend_http_ready_ms"]) for r in data] + vmax = max(vals) + n = len(data) + bw = plot_w / n * 0.7 + gap = plot_w / n + out = [f''] + out.append(f'' + 'backend-http-ready per launch (ms) - lower is better') + # y gridlines + for frac in (0, 0.25, 0.5, 0.75, 1.0): + yv = vmax * frac + y = pad_t + plot_h - plot_h * frac + out.append(f'') + out.append(f'{yv/1000:.0f}s') + for i, r in enumerate(data): + v = int(r["backend_http_ready_ms"]) + bh = plot_h * v / vmax + x = pad_l + i * gap + (gap - bw) / 2 + y = pad_t + plot_h - bh + color = COLD if r["class"] == "cold" else WARM + out.append(f'') + out.append(f'{v/1000:.0f}s') + out.append(f'{r["version"]}') + out.append(f'' + f'warm') + out.append(f'' + f'cold (post-update)') + out.append('') + return "\n".join(out) + + +def phases_chart(data): + warm = [r for r in data if r["class"] == "warm"] + cold = [r for r in data if r["class"] == "cold"] + + def med(rows_, key): + xs = sorted(int(r[key]) for r in rows_) + return xs[len(xs) // 2] if xs else 0 + + cases = [ + ("typical warm launch", med(warm, "app_launch_ms"), med(warm, "first_paint_ms"), med(warm, "backend_http_ready_ms")), + ("typical cold launch", med(cold, "app_launch_ms"), med(cold, "first_paint_ms"), med(cold, "backend_http_ready_ms")), + ] + w, h = 900, 260 + pad_l, pad_r, pad_t = 170, 30, 50 + plot_w = w - pad_l - pad_r + vmax = max(c[3] for c in cases) + out = [f''] + out.append(f'' + 'where startup time goes (backend dwarfs the shell)') + row_h = 46 + for i, (label, al, fp, br) in enumerate(cases): + y = pad_t + i * (row_h + 26) + out.append(f'{label}') + # backend is the full bar; app-launch+first-paint are the tiny left slice + bw_backend = plot_w * br / vmax + out.append(f'') + shell = al + fp + bw_shell = plot_w * shell / vmax + out.append(f'') + out.append(f'' + f'backend {br/1000:.1f}s (shell {shell/1000:.2f}s)') + out.append(f'' + 'dark = electron shell (app-launch + first-paint); colored = python backend') + out.append('') + return "\n".join(out) + + +def boot_chart(): + """Before/after grouped bars for the boot-phase breakdown (profile_boot.py).""" + path = os.path.join(HERE, "boot_breakdown.csv") + with open(path, newline="", encoding="utf-8") as f: + data = list(csv.DictReader(f)) + w, h = 900, 360 + pad_l, pad_r, pad_t, pad_b = 60, 30, 50, 120 + plot_w = w - pad_l - pad_r + plot_h = h - pad_t - pad_b + vmax = max(max(int(r["before_ms"]), int(r["after_ms"])) for r in data) + n = len(data) + group = plot_w / n + bw = group * 0.34 + out = [f''] + out.append(f'' + 'warm boot breakdown: before vs after (ms) - the service lifespan was the bottleneck') + for frac in (0, 0.5, 1.0): + y = pad_t + plot_h - plot_h * frac + out.append(f'') + out.append(f'{vmax*frac/1000:.1f}s') + for i, r in enumerate(data): + bx = pad_l + i * group + group / 2 + for j, (key, color, lab) in enumerate((("before_ms", COLD, "before"), ("after_ms", WARM, "after"))): + v = int(r[key]) + bh = plot_h * v / vmax + x = bx + (j - 1) * bw - bw * 0.05 + y = pad_t + plot_h - bh + out.append(f'') + out.append(f'{v/1000:.1f}s') + out.append(f'{r["phase"]}') + out.append(f'before') + out.append(f'after') + out.append('') + return "\n".join(out) + + +def appbuilder_chart(): + """Horizontal bars for the App Builder create-path breakdown. Returns None + if the measurement CSV hasn't been generated yet.""" + path = os.path.join(HERE, "appbuilder_breakdown.csv") + if not os.path.exists(path): + return None + with open(path, newline="", encoding="utf-8") as f: + raw = list(csv.DictReader(f)) + # Keep only real timing phases (drop the boolean/skipped/-1 rows). + data = [r for r in raw if r["ms"].lstrip("-").isdigit() and int(r["ms"]) >= 0 + and not r["phase"].strip().startswith("->")] + if not data: + return None + w = 980 + row_h, gap, pad_t, pad_l, pad_r = 30, 14, 56, 320, 90 + h = pad_t + len(data) * (row_h + gap) + 30 + vmax = max(int(r["ms"]) for r in data) or 1 + plot_w = w - pad_l - pad_r + out = [f''] + out.append(f'' + 'App Builder "create app -> live preview" breakdown (ms)') + for i, r in enumerate(data): + v = int(r["ms"]) + y = pad_t + i * (row_h + gap) + bw = max(plot_w * v / vmax, 1) + # download/npm = cold cost (red-ish), everything else = warm/per-app (green) + cold = ("npm" in r["phase"]) or ("cold" in r["phase"]) + color = COLD if cold else WARM + out.append(f'{r["phase"]}') + out.append(f'') + label = f'{v/1000:.2f}s' if v >= 1000 else f'{v}ms' + out.append(f'{label}') + out.append(f'' + 'green = warm/per-app cost; red = cold one-time download (npm with no archive)') + out.append('') + return "\n".join(out) + + +def main(): + data = rows() + open(os.path.join(HERE, "baseline_startup.svg"), "w", encoding="utf-8").write(bars_chart(data)) + open(os.path.join(HERE, "baseline_phases.svg"), "w", encoding="utf-8").write(phases_chart(data)) + open(os.path.join(HERE, "boot_breakdown.svg"), "w", encoding="utf-8").write(boot_chart()) + wrote = "baseline_startup.svg + baseline_phases.svg + boot_breakdown.svg" + ab = appbuilder_chart() + if ab: + open(os.path.join(HERE, "appbuilder_breakdown.svg"), "w", encoding="utf-8").write(ab) + wrote += " + appbuilder_breakdown.svg" + print("wrote " + wrote) + + +if __name__ == "__main__": + main() diff --git a/docs/perf/winv2/measure_appbuilder.py b/docs/perf/winv2/measure_appbuilder.py new file mode 100644 index 00000000..8e37fc2b --- /dev/null +++ b/docs/perf/winv2/measure_appbuilder.py @@ -0,0 +1,135 @@ +"""Granular App Builder first-app create/"download" profiler (winv2 Task #3). + +Incremental + bounded: each phase appends to appbuilder_breakdown.csv and flushes +the instant it finishes, so a slow/hung later phase can't erase earlier numbers. +Run UNBUFFERED (python -u) so progress is visible mid-run. Cheap phases first. + +Phases: + 1. seed workspace + link node_modules (per-app cost, uses real warm cache) + 2. download: npm install (cold, no archive) (the "slow as bricks" download) + 3. download: archive extract (new build path) (tar the just-installed nm, time extract) + 4. vite bind: cold vite cache (first app ever) + 5. vite bind: warm shared cache (subsequent apps) + +Isolated temp dirs; never mutates the user's real caches (read-only link to the +warm node_modules cache; vite cache is overridden to temp for the cold case). +""" +import asyncio +import os +import shutil +import subprocess +import tarfile +import tempfile +import time + +from backend.apps.outputs import view_builder_templates as vt +from backend.apps.outputs.runtime_proc import _find_free_port +from backend.apps.outputs.runtime import AppRuntime + +HERE = os.path.dirname(os.path.abspath(__file__)) +CSV = os.path.join(HERE, "appbuilder_breakdown.csv") +TMP = tempfile.mkdtemp(prefix="ab-measure-") +TMPL_FRONTEND = os.path.join(vt.WEBAPP_TEMPLATE_DIR, "frontend") +VITE_DEADLINE = 90 + +with open(CSV, "w", encoding="utf-8") as f: + f.write("phase,ms,note\n") + + +def lap(t): + return round((time.perf_counter() - t) * 1000) + + +def record(name, ms, note=""): + print(f"{ms:8d} ms {name}" + (f" ({note})" if note else ""), flush=True) + with open(CSV, "a", encoding="utf-8") as f: + f.write(f'"{name}",{ms},"{note}"\n') + f.flush() + + +def phase_seed(): + ws = os.path.join(TMP, "ws-seed") + t = time.perf_counter() + vt.seed_webapp_template_workspace(ws, _find_free_port()) + ms = lap(t) + present = os.path.exists(os.path.join(ws, "frontend", "node_modules")) + record("seed workspace + link node_modules (per app)", ms, "nm linked" if present else "NO nm") + + +def phase_npm_and_extract(): + npm = vt._resolve_npm() + if not npm: + record("download: npm install (cold)", -1, "skipped: no npm") + return + work = os.path.join(TMP, "npm_cold") + os.makedirs(work, exist_ok=True) + shutil.copyfile(os.path.join(TMPL_FRONTEND, "package.json"), os.path.join(work, "package.json")) + lock = os.path.join(TMPL_FRONTEND, "package-lock.json") + cmd = [*npm, "install", "--prefer-offline", "--no-audit", "--no-fund", "--loglevel=error"] + if os.path.exists(lock): + shutil.copyfile(lock, os.path.join(work, "package-lock.json")) + cmd = [*npm, "ci", "--prefer-offline", "--no-audit", "--no-fund", "--loglevel=error"] + t = time.perf_counter() + try: + r = subprocess.run(cmd, cwd=work, capture_output=True, text=True, timeout=240) + record("download: npm install (cold, no archive)", lap(t), "ok" if r.returncode == 0 else f"rc={r.returncode}") + except subprocess.TimeoutExpired: + record("download: npm install (cold, no archive)", -1, "TIMEOUT 240s") + return + + nm = os.path.join(work, "node_modules") + if not os.path.isdir(nm): + return + # Reuse that node_modules to time the archive build + extract (new path). + archive = os.path.join(TMP, "nm.tar.gz") + t = time.perf_counter() + with tarfile.open(archive, "w:gz") as tar: + tar.add(nm, arcname="node_modules") + record("build-time: tar node_modules -> archive", lap(t), f"{os.path.getsize(archive)//(1024*1024)}MB") + exd = os.path.join(TMP, "extract"); os.makedirs(exd, exist_ok=True) + t = time.perf_counter() + with tarfile.open(archive, "r:gz") as tar: + tar.extractall(exd) + record("download: archive extract (new build path)", lap(t)) + + +async def _bind_once(label, vite_cache_dir): + ws = os.path.join(TMP, f"ws-{label}") + vt.seed_webapp_template_workspace(ws, _find_free_port()) + if vite_cache_dir: + os.environ["OPENSWARM_VITE_CACHE_DIR"] = vite_cache_dir + else: + os.environ.pop("OPENSWARM_VITE_CACHE_DIR", None) + rt = AppRuntime(f"ws-{label}", ws) + t = time.perf_counter() + await rt.start() + deadline = time.perf_counter() + VITE_DEADLINE + while rt.frontend_url is None and time.perf_counter() < deadline: + await asyncio.sleep(0.1) + bound = rt.frontend_url is not None + ms = lap(t) if bound else -1 + try: + await rt.stop() + except Exception: + pass + record(f"vite bind ({label})", ms, "bound" if bound else f"TIMEOUT {VITE_DEADLINE}s") + + +async def main(): + print(f"temp: {TMP}", flush=True) + for fn in (phase_seed, phase_npm_and_extract): + try: + fn() + except Exception as e: + record(fn.__name__, -1, f"ERR {type(e).__name__}: {e}") + for label, cache in (("cold vite cache", os.path.join(TMP, "vite_cold")), ("warm shared cache", None)): + try: + await _bind_once(label, cache) + except Exception as e: + record(f"vite bind ({label})", -1, f"ERR {type(e).__name__}: {e}") + print("done", flush=True) + shutil.rmtree(TMP, ignore_errors=True) + + +if __name__ == "__main__": + asyncio.run(main()) diff --git a/docs/perf/winv2/measure_vite.py b/docs/perf/winv2/measure_vite.py new file mode 100644 index 00000000..8bc9ef57 --- /dev/null +++ b/docs/perf/winv2/measure_vite.py @@ -0,0 +1,70 @@ +"""Vite-bind-only measurement (winv2 Task #3, part 2). + +Split out from measure_appbuilder.py because Python's tarfile gzip of a full +node_modules is pathologically slow and was eating the time budget before the +vite phases ran. This does ONLY the two vite binds (cold vite cache = first app +ever; warm shared cache = subsequent apps) and APPENDS to appbuilder_breakdown.csv. +No tar, no npm. Run unbuffered. +""" +import asyncio +import os +import shutil +import tempfile +import time + +from backend.apps.outputs import view_builder_templates as vt +from backend.apps.outputs.runtime_proc import _find_free_port +from backend.apps.outputs.runtime import AppRuntime + +HERE = os.path.dirname(os.path.abspath(__file__)) +CSV = os.path.join(HERE, "appbuilder_breakdown.csv") +TMP = tempfile.mkdtemp(prefix="ab-vite-") +VITE_DEADLINE = 100 + + +def record(name, ms, note=""): + print(f"{ms:8d} ms {name}" + (f" ({note})" if note else ""), flush=True) + with open(CSV, "a", encoding="utf-8") as f: + f.write(f'"{name}",{ms},"{note}"\n') + f.flush() + + +async def bind_once(label, vite_cache_dir): + ws = os.path.join(TMP, f"ws-{label.replace(' ', '_')}") + vt.seed_webapp_template_workspace(ws, _find_free_port()) + if not os.path.exists(os.path.join(ws, "frontend", "node_modules")): + record(f"vite bind ({label})", -1, "no node_modules linked") + return + if vite_cache_dir: + os.environ["OPENSWARM_VITE_CACHE_DIR"] = vite_cache_dir + else: + os.environ.pop("OPENSWARM_VITE_CACHE_DIR", None) + rt = AppRuntime(f"ws-{label}", ws) + t = time.perf_counter() + await rt.start() + deadline = time.perf_counter() + VITE_DEADLINE + while rt.frontend_url is None and time.perf_counter() < deadline: + await asyncio.sleep(0.1) + bound = rt.frontend_url is not None + ms = round((time.perf_counter() - t) * 1000) if bound else -1 + try: + await rt.stop() + except Exception: + pass + record(f"vite bind ({label})", ms, "bound" if bound else f"TIMEOUT {VITE_DEADLINE}s") + + +async def main(): + print(f"temp: {TMP}", flush=True) + for label, cache in (("cold vite cache", os.path.join(TMP, "vite_cold")), + ("warm shared cache", None)): + try: + await bind_once(label, cache) + except Exception as e: + record(f"vite bind ({label})", -1, f"ERR {type(e).__name__}: {e}") + print("done", flush=True) + shutil.rmtree(TMP, ignore_errors=True) + + +if __name__ == "__main__": + asyncio.run(main()) diff --git a/docs/perf/winv2/profile_boot.py b/docs/perf/winv2/profile_boot.py new file mode 100644 index 00000000..86a49f10 --- /dev/null +++ b/docs/perf/winv2/profile_boot.py @@ -0,0 +1,67 @@ +"""Per-phase + per-SubApp-lifespan boot profiler (winv2). + +Warm import is ~1.3s but backend-http-ready is ~9-10s, so the gap is the +lifespan startup (SubApp lifespans are entered sequentially in config/Apps.py +before uvicorn serves). This times each one to find what blocks the HTTP bind. + +Run with the bundled interpreter from the resources dir, e.g.: + python-env/python.exe docs/perf/winv2/profile_boot.py +It spawns the same subprocesses a real boot does (9router etc.); the +AsyncExitStack unwinds at the end. Kill any straggler node/9router after. +""" +import asyncio +import os +import time + +os.environ.setdefault("OPENSWARM_AUTH_TOKEN", "x") + +_t0 = time.perf_counter() +import backend.main # noqa: F401 (builds main_app; full import tree) +_import_ms = (time.perf_counter() - _t0) * 1000 + +from contextlib import AsyncExitStack # noqa: E402 + +from backend.apps.health.health import health # noqa: E402 +from backend.apps.agents.agents import agents # noqa: E402 +from backend.apps.skills.skills import skills # noqa: E402 +from backend.apps.tools_lib.tools_lib import tools_lib # noqa: E402 +from backend.apps.modes.modes import modes # noqa: E402 +from backend.apps.settings.settings import settings # noqa: E402 +from backend.apps.mcp_registry.mcp_registry import mcp_registry # noqa: E402 +from backend.apps.skill_registry.skill_registry import skill_registry # noqa: E402 +from backend.apps.outputs.outputs import outputs # noqa: E402 +from backend.apps.dashboards.dashboards import dashboards # noqa: E402 +from backend.apps.swarm.swarm import swarm # noqa: E402 +from backend.apps.service.service import service # noqa: E402 +from backend.apps.subscription.router import subscription # noqa: E402 +from backend.apps.auth.router import auth # noqa: E402 +from backend.apps.web.web import web # noqa: E402 +from backend.apps.agents.proxy.anthropic_proxy import anthropic_proxy # noqa: E402 + +SUBS = [health, agents, skills, tools_lib, modes, settings, mcp_registry, + skill_registry, outputs, dashboards, swarm, service, subscription, + auth, web, anthropic_proxy] + + +async def main(): + print(f"{_import_ms:8.0f} ms import backend.main (full tree)") + print("-" * 48) + total = 0.0 + async with AsyncExitStack() as stack: + for s in SUBS: + t = time.perf_counter() + try: + await asyncio.wait_for(stack.enter_async_context(s.lifespan()), timeout=60) + except Exception as e: + print(f" ERR lifespan {s.name}: {type(e).__name__}") + continue + dt = (time.perf_counter() - t) * 1000 + total += dt + print(f"{dt:8.0f} ms lifespan {s.name}") + print("-" * 48) + print(f"{total:8.0f} ms all lifespans") + print(f"{_import_ms + total:8.0f} ms import + lifespans (approx backend-ready floor)") + + +if __name__ == "__main__": + asyncio.run(main()) diff --git a/docs/perf/winv2/profile_startup.sh b/docs/perf/winv2/profile_startup.sh new file mode 100644 index 00000000..259a1a2c --- /dev/null +++ b/docs/perf/winv2/profile_startup.sh @@ -0,0 +1,31 @@ +#!/bin/bash +# Re-extract real packaged-app startup timings from the installed app's backend +# log. Prints one row per launch: timestamp, version, app-launch ms, +# first-paint ms, backend-http-ready ms. Pipe to a CSV for the metrics table. +# +# Usage: bash profile_startup.sh [path-to-backend.log] +# Default log: AppData/Roaming/openswarm/data/backend.log + +LOG="${1:-$HOME/AppData/Roaming/openswarm/data/backend.log}" +if [[ ! -f "$LOG" ]]; then + echo "no backend.log at $LOG" >&2 + exit 1 +fi + +echo "launch_ts,version,app_launch_ms,first_paint_ms,backend_http_ready_ms,class" +awk ' + /===== launch/ { + if (ts != "") emit() + ts=$3; ver="" + for (i=1;i<=NF;i++) if ($i ~ /^\(app$/) { ver=$(i+1); gsub(/,/,"",ver) } + al=""; fp=""; br="" + } + /\[perf\] app-launch t=/ { sub(/.*t=/,""); al=$0 } + /\[perf\] first-paint t=/ { sub(/.*t=/,""); fp=$0 } + /\[perf\] backend-http-ready t=/ { sub(/.*t=/,""); br=$0 } + END { if (ts != "") emit() } + function emit() { + cls = (br+0 > 20000) ? "cold" : "warm" + printf "%s,%s,%s,%s,%s,%s\n", ts, ver, al, fp, br, cls + } +' "$LOG"