repro-concurrent-explore.mjs 5.3 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119
  1. #!/usr/bin/env node
  2. // Reproduction harness A — does the shared daemon serialize concurrent explore?
  3. //
  4. // Mirrors the daemon's reality: ONE CodeGraph + ONE ToolHandler (as MCPEngine
  5. // shares across all sessions), then fires N concurrent codegraph_explore calls
  6. // and measures:
  7. // - each call's wall-clock latency + completion order
  8. // - an event-loop HEARTBEAT (setInterval 50ms): the max gap between ticks is a
  9. // direct measure of how long synchronous compute blocked the loop. In the
  10. // real daemon a blocked loop can't flush a finished response or read the
  11. // next request, so this gap is what starves the MCP transport.
  12. //
  13. // Usage: node repro-concurrent-explore.mjs <repo-with-.codegraph> <N> [timeoutMs]
  14. import { pathToFileURL } from 'node:url';
  15. import { resolve } from 'node:path';
  16. import { performance } from 'node:perf_hooks';
  17. const [, , repo, nRaw, timeoutRaw] = process.argv;
  18. if (!repo) {
  19. console.error('usage: repro-concurrent-explore.mjs <repo> <N=10> [timeoutMs=60000]');
  20. process.exit(1);
  21. }
  22. const N = Number(nRaw) || 10;
  23. const TIMEOUT_MS = Number(timeoutRaw) || 60000; // ~ MCP SDK default request timeout
  24. const load = async (rel) => import(pathToFileURL(resolve(rel)).href);
  25. const idx = await load('dist/index.js');
  26. const tools = await load('dist/mcp/tools.js');
  27. const CodeGraph = idx.default?.default ?? idx.default ?? idx.CodeGraph;
  28. const ToolHandler = tools.ToolHandler ?? tools.default?.ToolHandler;
  29. // Distinct queries so no two calls are trivially identical. Mix of NL questions
  30. // (exercise FTS + RWR over the whole graph) — the expensive explore path.
  31. const QUERIES = [
  32. 'how does the text model handle edits and undo',
  33. 'how does the file service watch for changes on disk',
  34. 'how does the keybinding service resolve a chord to a command',
  35. 'how does the extension host activate an extension',
  36. 'how does the editor render decorations in the viewport',
  37. 'how does the search service stream results to the UI',
  38. 'how does the terminal process manager spawn a shell',
  39. 'how does the configuration service merge user and workspace settings',
  40. 'how does the debug adapter forward breakpoints to the runtime',
  41. 'how does the quick input widget filter its items',
  42. 'how does the notification service queue and show toasts',
  43. 'how does the git extension compute the diff for a file',
  44. 'how does the language features registry dispatch a hover request',
  45. 'how does the workbench layout restore editor groups on reload',
  46. 'how does the storage service persist state between sessions',
  47. 'how does the menu service build a context menu from contributions',
  48. ];
  49. const cg = CodeGraph.openSync(repo);
  50. let fileCount = 0;
  51. try { fileCount = cg.getStats().fileCount; } catch {}
  52. const handler = new ToolHandler(cg);
  53. // --- event-loop heartbeat ---
  54. let lastTick = performance.now();
  55. let maxGap = 0;
  56. const gaps = [];
  57. const hb = setInterval(() => {
  58. const now = performance.now();
  59. const gap = now - lastTick;
  60. lastTick = now;
  61. if (gap > 60) gaps.push(Math.round(gap)); // expected ~50ms; record stalls
  62. if (gap > maxGap) maxGap = gap;
  63. }, 50);
  64. function runOne(i) {
  65. const q = QUERIES[i % QUERIES.length];
  66. const startedAt = performance.now();
  67. let timer;
  68. const timeout = new Promise((res) => {
  69. timer = setTimeout(() => res({ timedOut: true }), TIMEOUT_MS);
  70. });
  71. const work = handler
  72. .execute('codegraph_explore', { query: q })
  73. .then((r) => ({ ok: !r.isError, chars: r.content?.[0]?.text?.length ?? 0 }))
  74. .catch((e) => ({ ok: false, err: String(e?.message ?? e) }));
  75. return Promise.race([work, timeout]).then((r) => {
  76. clearTimeout(timer);
  77. return { i, q, ms: Math.round(performance.now() - startedAt), ...r };
  78. });
  79. }
  80. // Baseline: one warm single call (so the first-call cold paths don't skew N).
  81. const warmStart = performance.now();
  82. await runOne(0);
  83. const warmMs = Math.round(performance.now() - warmStart);
  84. // Reset heartbeat stats for the concurrent run.
  85. gaps.length = 0; maxGap = 0; lastTick = performance.now();
  86. const batchStart = performance.now();
  87. const results = await Promise.all(Array.from({ length: N }, (_, i) => runOne(i)));
  88. const batchMs = Math.round(performance.now() - batchStart);
  89. clearInterval(hb);
  90. const lat = results.map((r) => r.ms).sort((a, b) => a - b);
  91. const timeouts = results.filter((r) => r.timedOut).length;
  92. const p = (q) => lat[Math.min(lat.length - 1, Math.floor(q * lat.length))];
  93. console.log('='.repeat(64));
  94. console.log(`repo=${repo}`);
  95. console.log(`fileCount=${fileCount} N=${N} perCallTimeout=${TIMEOUT_MS}ms`);
  96. console.log(`single warm explore: ${warmMs}ms`);
  97. console.log('-'.repeat(64));
  98. console.log(`concurrent batch wall-clock: ${batchMs}ms`);
  99. console.log(`per-call latency min=${lat[0]} p50=${p(0.5)} p90=${p(0.9)} max=${lat[lat.length - 1]} (ms)`);
  100. console.log(`TIMEOUTS (>${TIMEOUT_MS}ms): ${timeouts} / ${N}`);
  101. console.log(`event-loop max stall: ${Math.round(maxGap)}ms stalls>60ms: ${gaps.length}`);
  102. console.log(` sum of stalls: ${gaps.reduce((a, b) => a + b, 0)}ms biggest 5: ${gaps.sort((a,b)=>b-a).slice(0,5).join(', ')}`);
  103. console.log('-'.repeat(64));
  104. console.log('SERIALIZATION CHECK:');
  105. console.log(` if serialized, batch ≈ N×single = ~${N * warmMs}ms; actual=${batchMs}ms (ratio ${(batchMs / (N * warmMs)).toFixed(2)})`);
  106. console.log(` max latency / single = ${(lat[lat.length - 1] / warmMs).toFixed(1)}× (≈N means last call waited for all others)`);
  107. console.log('='.repeat(64));
  108. try { cg.close?.(); } catch {}