Skip to content

test(mcp): diagnose startup stalls (do not merge)#41947

Draft
Skn0tt wants to merge 5 commits into
microsoft:mainfrom
Skn0tt:skn0tt-diagnose-mcp-startup-stalls
Draft

test(mcp): diagnose startup stalls (do not merge)#41947
Skn0tt wants to merge 5 commits into
microsoft:mainfrom
Skn0tt:skn0tt-diagnose-mcp-startup-stalls

Conversation

@Skn0tt

@Skn0tt Skn0tt commented Jul 23, 2026

Copy link
Copy Markdown
Member

Caution

Temporary diagnostic PR. Do not merge as-is.

This adds a PWTEST_MCP_STARTUP_TRACE-gated JSONL timeline around MCP CLI, daemon, browser, registry and dashboard startup. The fixture retains one file per test and uploads it even when the test times out.

The corrected 30-job run localises the delays to Chromium servicing its earliest protocol work:

  • Ubuntu Chrome's first annotation open took 1.7-16.2s across ten fresh runners (8.8s median). The first Browser.getVersion response took 0.8-11.0s (6.1s median).
  • Windows Chrome showed the same pattern: first open took 4.0-11.7s and Browser.getVersion accounted for up to 9.9s.
  • Windows Edge sample 9 reproduced the original failure. show took 35.9s: 10.3s launching the persistent browser, including 8.5s waiting for its initial page, then 25.2s in dashboard page.goto. Of that, 25.0s was inside Page.navigate before Chromium issued the first HTTP request.

The surrounding machinery is fast across the run: daemon spawn p95 7ms, browser process spawn p95 12ms, dashboard HTTP readiness p95 47ms, registry publication p95 6ms, browser bind p95 5ms and browser teardown p95 3ms. This rules out the CLI/daemon connection, dashboard HTTP server, registry publication and teardown as the source of the 29-38s stalls.

The earlier Ubuntu runner losses were caused by the diagnostic itself. Cleanup killed the process group of an observed, non-detached MCP server PID; on Linux that group also contained npm and the test runner. The corrected run completed all ten Ubuntu jobs. Resource telemetry stayed healthy throughout: roughly 14 GB available RAM, no swap movement, stable process counts and modest load.

28/30 jobs passed. Windows Chrome sample 9 hit an unrelated existing CLI assertion. Windows Edge sample 9 timed out while the 25.2s dashboard navigation above was still running.

So the useful conclusion is: this is browser-side, after Chromium has spawned and the pipe transport exists. The trace does not tell us whether Chromium itself is blocked or the hosted VM is delaying it through scheduling, storage or antivirus work. This PR remains diagnostic and must not merge as-is.

Copilot-Session: b62093c2-7f1f-46d8-9f9a-be7e30a965ab
@github-actions

This comment has been minimized.

@github-actions

This comment has been minimized.

Skn0tt and others added 2 commits July 23, 2026 16:24
Split Chromium connection and navigation startup into individual diagnostic
phases so the next sampled CI run can identify the exact stalled operation.
Limit matrix concurrency to reduce hosted-runner fleet pressure.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: b62093c2-7f1f-46d8-9f9a-be7e30a965ab
Stop traced Ubuntu jobs before the hosted VM loses communication, and retain
resource telemetry alongside the partial startup timelines.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: b62093c2-7f1f-46d8-9f9a-be7e30a965ab
@github-actions

This comment has been minimized.

@github-actions

This comment has been minimized.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: b62093c2-7f1f-46d8-9f9a-be7e30a965ab
@github-actions

This comment has been minimized.

@github-actions

This comment has been minimized.

Retain Perfetto traces when startup timeline phases exceed five seconds,
and recover partial traces after worker timeouts for CI artifact upload.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: b62093c2-7f1f-46d8-9f9a-be7e30a965ab
@github-actions

Copy link
Copy Markdown
Contributor

Test results for "MCP startup diagnostic (temporary)"

1 failed
❌ [chrome] › mcp/cli-json.spec.ts:192 › request and per-part commands return JSON result @mcp-startup-diagnostic-windows-latest-chrome-sample-4

19479 passed, 1430 skipped


Merge workflow run.

@github-actions

Copy link
Copy Markdown
Contributor

🟡 One failure — I can't certify it, but nothing points at this PR

Hi, I'm the Playwright bot and I took a first look at the CI failures.

The latest merged report (run 30100485338) has one red: [chrome] › mcp/cli-json.spec.ts:192 › request and per-part commands return JSON result on windows-latest chrome sample 4. It's a latent race in the test, and this diagnostic PR's 10× serial reruns are exactly what surface those — but I have no off-branch occurrence to prove it, so I'm calling it uncertain.

Details

This is a diagnostic PR: it adds PWTEST_MCP_STARTUP_TRACE-gated startup tracing and reruns the MCP suite 10× serially on fresh Windows/Ubuntu runners to surface latent races. The product change is inert unless the env var is set, and even active it only appends JSONL and wraps goto() — it doesn't touch request capture, click dispatch, or the requests listing that this test asserts on.

Uncertain

  • [chrome] › mcp/cli-json.spec.ts:192 › request and per-part commands return JSON result — failed once with TypeError: Cannot read properties of null (reading '1'). That's line 205: list.match(/^(\d+)\. \[POST\] [^ ]+\/api =>/m)![1]. The click fires an async fetch('/api', {method:'POST'}); if the POST hasn't landed in the requests list when it's read, the regex returns null and the ! assertion throws. A timing race in the test itself, not a timeout/infra signature.

    Per our flake rule I need the same test failing where this PR can't be responsible, and I don't have it: across the results DB this test is green in 1198/1199 chrome runs (and 0 failures across webkit 1148, chromium 1141, firefox 1117, msedge 258). The single recorded failure is this PR's own run (30088955677, sample-4), single attempt, no retry rescue. No occurrence off this branch. So I won't certify it as pre-existing.

    That said, a real regression is unlikely — the diff doesn't reach the click/request-capture path this test exercises. Reads like a fresh-runner race the 10× serial harness shook loose.

    To be sure either way: rerun the MCP suite for this test, or run the same 10× harness against an unmodified main — if it races there too, it's pre-existing.

Triaged by the Playwright bot - agent run

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant