Startup responsiveness — audit fix plan (tracking issue with TODOs)

[msarson]

Single tracking issue for the remaining fixes from the multi-agent startup-chain audit (report: docs/audits/startup-chain-audit-2026-07-09.md, findings JSON alongside; 64 agents, 39 confirmed findings). Symptoms: tree spinner on project expansion, Structure view spin on tab switch, general unresponsiveness in the first minutes after opening a large solution. Ranked diagnosis (details + evidence in the report): - H1 — server request-queue saturation during the first minutes, doubled by the duplicate startup pipeline (findFile storms, didOpen force-open storm, per-lens CodeLens FAR scans). - H2 — every tree refresh rebuilds the root with fresh nodes, discarding cached children → getProjectFiles re-issued for expanded projects (why the cached-children early-return didn't help). - H3 — Structure-view generation race: tab switch clears symbols, a second fetch 100ms later discards the one that renders → blank/spin whenever the server isn't instant. ## Surgical fixes (each <1h, low risk — file:line targets in report §2a) - [x] 1. Tree: carry over node.children keyed by project GUID across root rebuilds; set TreeItem.id (SolutionTreeDataProvider.ts:1374-1409) — kills H2 � done in 624a4f9 - [x] 2. Single-source startup completion: eager path disposes the solutionReady handler / latch (SolutionInitializer.ts:427-433) — halves H1 � done in 624a4f9 - [x] 3. beginActivationRefresh() BEFORE refreshSolutionTreeView(); try/finally around markActivationComplete() (SolutionInitializer.ts:343-350) � done in 624a4f9 - [x] 4. Structure view: don't clear _lastKnownSymbols on tab switch; single-flight per (uri,version); discard path awaits the winning fetch (StructureViewProvider.ts:91, 811) — kills H3 � done in c16d3ca - [x] 5. revealActiveSelection must not bump the symbol-request generation or issue its own fetch (StructureViewProvider.ts:256) � done in c16d3ca - [x] 6. symbolsRefreshed notification: refresh only when uri matches the active editor; consider dropping the didOpen-side notification (LanguageServerManager.ts:206, server.ts:528) � done in c16d3ca - [x] 7. Server findFile: negative-cache misses + in-flight coalescing + first-hit early exit prioritising the requester's project (solutionManager.ts:538-546) — biggest server-queue win � done in 6b3e84c - [x] 8. CodeLens resolve: propagate LSP CancellationToken into provideReferences + 200-500ms wall-clock budget; linked-token cancel for the 15s race (server.ts:871-922, :2390) � done in 10b4b0f - [x] 9. Delete the no-op refreshOpenDocuments(undefined) costing 0.9-1.6s of awaited activation (ActivationManager.ts:223) � done in 10b4b0f - [x] 10. Stop force-opening session-restored tabs — iterate workspace.textDocuments only (ExtensionHelpers.ts:36-44) � done in 10b4b0f - [x] 11. Tree getChildren: ~5s timeout + retryable error node + in-flight dedup per projectGuid (SolutionTreeDataProvider.ts:508, :576) � done in acaa7f8 - [x] 12. Fix DocumentManager module-var leak in the wrapper (extension.ts:295) � done in 10b4b0f - [x] 13. Tree getTreeItem: set openFile command up front, resolve path lazily in the command handler — removes fire-and-forget findFile per node AND fixes dead clicks (SolutionTreeDataProvider.ts:1088) � done in 624a4f9 - [x] 14. Decisive experiment (do early): LSP dispatch-queue wrapper logging {method, queue-wait, self-time} per request for the first 3 minutes (~20 lines, server.ts) — arbitrates H1/H2/H3 residuals conclusively (report §3) � done in 3237f94 ## Structural fixes (report §2b) - [x] S1. One startup pipeline: clarion/solutionReady as the sole completion driver; remove the eager 15s-race fetch, the 1s sleep, the duplicate getSolutionTree registration; shared in-flight fetch promise � done in 001ee85 (duplicate registration removed, 1s sleep deleted, shared in-flight fetch; the eager fetch itself is KEPT � it now renders the tree in ~2s and dedup makes it free) - [ ] S2. Replace the activation boolean with refcounted/token-scoped suppression gated on a server clarion/indexingReady signal � parked pre-1.0.0: refactor with regression surface; current VM captures no longer implicate the activation boolean (try/finally hardened in fix 3) - [ ] S3. Batch clarion/findFiles (one request per document) + server-side O(1) basename index replacing the 40-project fan-out + client O(1) map + async probes + global negative cache � partially shipped (negative cache + coalescing + early exit in 6b3e84c); O(1) basename index + batched findFiles ride with #294/#295 - [ ] S4. Inverted reference index → CodeLens resolve O(1), removes per-lens FAR (#294); lower cooperativeScan FILES_PER_YIELD 25→5 or time-based checkpoint � yield-interval part shipped (acaa7f8); the inverted reference index IS #294 - [x] S5. Version-keyed documentSymbol caching on both ends � done in 001ee85 (server-side; client side already covered by the fix-4 single-flight) - [ ] S6. Debounced, targeted watcher handling; in-place DocumentManager rescan instead of dispose/recreate � parked pre-1.0.0: same rationale; matters most on regenerated-files workflows, revisit with #295 ## Pre-1.0.0-release checklist (carried from the perf campaign) - [x] Decide perf-log verbosity for the marketplace build — decided in 10debe4, revised in c3cf3a5 per Mark: perf channels are OPT-IN via the new clarion.log.performance.enabled setting (default off; instrumentation always runs, only output gated — flip the setting + reload for the full support timeline); DocumentRefreshManager + StructureViewProvider info chatter drop to errors-only - [x] Tighten .vscodeignore — done in 10debe4: .mcp.json(+.bak), .claude/, .husky/, .clarion-debug/, esbuild.mjs, .mocharc-client.json, scripts/, package-locks all excluded; VSIX now 24 files Related (kept separate, referenced): #291 (remove blocking progress toast), #292 (dll-module diagnostic false positive), #294 (inverted reference index), #295 (off-thread indexing architecture), #296 (tree provider defects — items 1/11/13 above overlap; close together).

[msarson]

Batch 5 (acaa7f8) — what run 2's logs proved and what changed:

Run 2 evidence (fix 14 wrapper's first catch): LSP slow handler | clarion/updatePaths, ms=19000 — but the 18.3s stall inside it was starvation, not work (all 40 projects report identical read_parse_ms≈18300; lag sampler caught a single 6.2s sync block). The hog never logged because it registers through the dedicated registrars (onDocumentSymbol, onCodeLens, onFoldingRanges, didChange sync path…), which bypass connection.onRequest.

• Instrumentation now wraps every onXxx(handler) registrar + languages.semanticTokens/inlayHint — next run names the hog conclusively
• Fix 11 shipped: tree expand now logs at request time, dedups in-flight per GUID, times out at 15s, and renders a "couldn't load — click to retry" node instead of the eternal silent spinner (clarion/getProjectFiles previously had NO timeout — that was the "expand does nothing, no logs" symptom)
• S4 partial: ReferencesProvider.FILES_PER_YIELD 25→5 — documentSymbol timed out 8+ consecutive times (10s each) behind the post-solutionReady FAR/validator window

Also confirmed working in run 2: startup fallback race fixed (no duplicate pass), refresh(true) 15009ms→1278ms, SDI disk cache 4.6s→1.2s.

[msarson]

Run 3 evidence + batch 6 (d43886a):

Run 3 improvements confirmed: clarion/updatePaths 19000ms→5962ms, per-project reads 18.3s→55-140ms (disk cache warm), solutionReady at +21s, startup pipeline single-pass, and the new expand timeout/retry node rendered correctly instead of the eternal spinner.

Remaining defect run 3 exposed: tree expand at +44s starved to its 15s timeout on an in-memory getProjectFiles lookup. Timeline: SDI done +28s → batch revalidation (all docs Promise.all'd) pinned the loop 35s+ because cross-file validators fall back to directory scans while the FRG doesn't exist yet. Batch 6 flips the order: 2s settle → FRG first (yields every 10 files — interactive requests interleave) → revalidation one doc at a time, each benefiting from the built graph.

Still on the radar (named by the new instrumentation):

• onDocumentLinks ms=3601 pre-solution — document-link provider blocks 3.6s during load
• ~5.4s sync block inside parseSolution between cache-miss check and RED parse outcome (sync .red parsing / search-path setup) — one-time but starves the queue during load

[msarson]

Run 5 + batch 8 (2b5893a) — the starvation mechanism, finally pinned:

Run 5 disproved the "one long sync stretch" theory: time-sliced validator loops were in place, yet a tree expand still starved 15s through gl1.clw's validator window — on an in-memory getProjectFiles lookup, with FRG done in 1.3s and the queue otherwise healthy.

Actual mechanism: validateTextDocument ran its 7 validators via Promise.all. Concurrent promise chains that await mostly-cached (already-resolved) promises advance on the microtask queue — Node never reaches the poll phase to read incoming LSP messages while any chain still has work. One validator's setImmediate yield is simply absorbed by the other six chains. This is why every yield-based mitigation half-worked.

Batch 8:

• Server: the batch sdiReady revalidation runs validators strictly sequentially with a real macrotask yield between each (user-edit validation keeps the concurrent path; total work is identical on one thread anyway)
• Client: the tree no longer depends on the server answering at all — on getProjectFiles timeout (now 5s) the provider parses the project's own .cwproj locally (<Compile Include> entries — the same source the server reads) and builds file nodes from it. Clicks already resolve paths lazily (fix 13). The retry node remains only for both-paths-failed.

This is the strongest argument yet for S-fix/#295 (off-thread indexing): the single-threaded LSP loop fundamentally cannot guarantee interactive latency while any CPU-bound analysis runs, no matter how cooperatively it yields.

[msarson]

Run 6 + batch 9 (197c474):

Run 6 validated the sequential-validator design — an onCodeAction was served in the gap between validators, and the sliced validators collapsed (gl1 discardedReturn 3.9s→913ms, missingIncludes 2.1s→7ms with SDI warm; caching also compounds in sequential order). The tree populated via the cwproj fallback (163 files) — first time expansion has ever produced content on the VM.

Remaining occupancy = the unsliced tail validators, led by missingImpl: an app-main CLW declares one MODULE per generated file (~178) and each iteration loads and tokenizes that file on cache miss — 37s+ of loop time. Now time-sliced (plus undeclaredVar's per-candidate findSymbol loop and ifaceImpl's per-class loop).

UX change: tree expansion is now local-first — the provider parses the project's cwproj directly (milliseconds, zero server dependency); the server request is only a fallback for an unreadable cwproj. The 5s wait is gone entirely.

[msarson]

Run 7 — VERIFIED by Mark: "can expand in an instant now."

Log confirms across the board:

• Tree expand: local cwproj fallback | project=ap1, files=163 — instant, zero server dependency, no timeout
• missingImpl on SQLInstallAndUpgrade: 1.86s and yielding (was the 37s monolith)
• gl1 discardedReturn 1.0s; SDI 3.1s; FRG 1.75s; startup COMPLETE at ~22s
• Worst event-loop block post-ready: ~1.4s (was 5-6s), interactive requests served throughout

Cumulative campaign scoreboard (0.9.9 VM baseline → now): solution load 7.9s→~5.5s server-side with 99%-unresolved RED bug fixed (#293), tree expand ∞/dead → instant, structure view race fixed, startup pipeline single-pass, FRG 25s→1.7s, SDI rogue scans killed + disk-cached, validators sequential+time-sliced.

Remaining before close: surgical 8 (CodeLens cancellation budget), 9, 10, 12; the named small hogs (onDocumentLinks ~3.2s pre-solution; ~5s sync stretch in RED/env init inside updatePaths); pre-release checklist; structural S1–S6 tracked for post-1.0.0 (#294/#295 do the heavy lifting).

[msarson]

Batch 10 (10b4b0f) — surgical list COMPLETE (all 14 items ticked).

• Fix 8: CodeLens resolve under a 500ms budget linked to the client token; partial shown as "N+ references", cache skipped on abort so a later resolve retries
• Fix 9: deleted the pre-DocumentManager no-op refreshOpenDocuments on the activation path (0.3-0.8s awaited enumeration for nothing)
• Fix 10: session-restored lazy tabs are no longer force-loaded (each force-load fired a didOpen → server tokenize+validate at the busiest startup moment)
• Fix 12: reinitializeEnvironment now assigns the fresh DocumentManager back to the module var (stale-instance injection + leak after solution reload)
• Bonus: onDocumentLinks during an announced load no longer builds a throwaway degraded-mode FRG (was 3.2s on the queue); links repopulate at solutionReady
• The last unattributed ~5s sync stretch inside parseSolution now has bisecting sub-phase marks (sln access / sln read / project scan loop / all project loads) — next VM capture names it

Remaining on this issue: that ~5s attribution, the pre-release checklist (perf-log verbosity, .vscodeignore), and structural S1–S6 (post-1.0.0, #294/#295).