Skip to content

feat(mcp): bounded first-load diagnostics experiment for #335 - #9

Merged
timeleft-- merged 4 commits into
developfrom
claude/issue-335-first-load-diagnostics
Oct 30, 2026
Merged

timeleft-- merged 4 commits into
developfrom
claude/issue-335-first-load-diagnostics

Conversation

@timeleft--

@timeleft-- timeleft-- commented Oct 29, 2026 •

Copy link
Copy Markdown
Member

A bounded experiment for question 1 of iaser-ai#335: why the card fails on first load in Claude web and ChatGPT web and recovers after one Retry. It is meant to locate the first missing step between the card read, the card's start, the host handshake, tool-result arrival and the first rendered answer, where that step is observable. It is not a permanent observability design; after the trials it is removed or narrowed to what proved useful.

Starting point

  • All four 10-28 failures are the host's own error box. The card's own failure texts never appear, so the host gave up before the card showed anything.
  • Before this change, every /mcp exchange was logged as {"event":"mcp.request","method":"POST"}. A read of an earlier deploy's card address fails with JSON-RPC -32602 inside an HTTP 200, and was logged exactly like a successful 1.75 MB read.

Changes

Log levels

  • Every record carries a level:
    • error: mcp.error and source.error;
    • warn: rejected or rate-limited card reports;
    • info: startup, mcp.request, source.start and source.complete;
    • debug: the measurement records below.
  • MCP_LOG_LEVEL is info (default) or debug. A diagnostic card implies debug, and setting info with one stops startup.
  • At info the server neither inspects nor wraps an exchange. It writes the same records as before, plus the level and error names and codes.
  • Dropping the debug lines from a measured deployment leaves exactly those records.

Server records, only at debug

  • mcp.rpc and mcp.response lines, joined by rid. mcp.request keeps only the HTTP method, as before.
  • The request is inspected from a tee, alongside the handler, up to 64 KiB actually read. It never holds up or alters the exchange; a larger body is recorded as oversize.
  • The request line has:
    • the JSON-RPC method;
    • for a card read, the address read and whether it is the one this instance serves;
    • for the handshake, the client's name, version and protocol;
    • for a tool call, the tool name.
  • The response line has the HTTP status, bytes, timings and stream: drained, cancelled or failed on this side. That is not proof the host received or rendered anything.
  • Responses up to 64 KiB are decoded as JSON-RPC for an error code.
  • view.prepared records the served card's address, size, whether it is a diagnostic card, and its connect origins.
  • Handler errors are logged by name and code. No question, answer or other parameter value is logged.

Card reports, only when MCP_VIEW_DIAGNOSTICS_ORIGIN is set

  • The card carries an ansari-diagnostics address in its head and may connect to that one origin. Its bytes, address and permissions change, so its trials are compared with the closed card's.
  • An early script runs before the bundle is parsed. It records errors, unhandled rejections, CSP violations and the arrival of the host's messages, by method name only.
  • It reports by itself at load, at pagehide and after 15 s without a start, so a bundle that never runs is still reported.
  • The stack's existing hooks add font loading, host-context delivery, how startup ended, and the first rendered answer or problem.
  • The receiver accepts only a fixed report shape, at most 8 KiB and 120 reports a minute per instance, and logs it as client-authored.
  • In the closed card the early script does nothing. A closed-card trial sets MCP_LOG_LEVEL=debug without the origin, to keep the server records.

Trials

  • scripts/first-load-trial.sh records the deployment release and the first attempt and Retry as separate windows.
  • scripts/first-load-timeline.mjs joins trials with Railway deployment and edge logs by time.
    • It flags windows with more than one MCP client, overlapping trials or another release as ambiguous.
    • It words findings as observations in a window, for example "no host message observed by its last report".

Validation

  • pnpm mcp verify: lint, typecheck, Node and Worker builds, 154/154 server tests and 78/78 browser checks.
  • Level test: a full exchange at info writes only the operational records; at debug, dropping the debug lines gives the same records. The test fails when measuring is forced on.
  • Bound test: a byte-bounded read of an endless stream stops after at most one chunk past the limit. The test fails when the bound is loosened.
  • Request inspection: an over-limit streamed request with no Content-Length is recorded as oversize, and the handler still answers.
  • The beacon refuses an over-limit streamed body and the 121st report in a minute.
  • Browser checks:
    • closed cards send no report and write no report line;
    • a diagnostic card sends load, ready and result reports that the server's parser accepts, with marks in startup order and no answer text;
    • a card whose bundle fails to parse still sends a load report, with no main mark and the SyntaxError.
  • The timeline was run against a local server:
    • a first attempt with a stale read and a pre-bundle report;
    • a clean Retry;
    • a window with two clients, flagged ambiguous.
  • The trial script was run with piped answers against a local server.
  • Gitleaks found no leaks.

One CSP violation is expected on every diagnostic load: zod's caught new Function('') capability probe under the card's script-src. The browser check treats it as the baseline; any other error fails.

Not included

🤖 Generated with Claude Code

Issue iaser-ai#335: in Claude web and ChatGPT web the host's own error replaced the
card on first load and one Retry recovered it. The card's own failure texts
never appeared, and the server logged every exchange as a bare `POST`, so a
stale card read (JSON-RPC -32602 inside HTTP 200) looked like a successful one.

- Server, always on: `mcp.request`/`mcp.response` lines joined by `rid`, with
  the JSON-RPC method, the card address read and whether it is current, the
  handshake's client and protocol, status, error code, bytes, timings and
  whether the client hung up. Handler errors log name and code only.
- Card, always on: an early script records script start, errors, rejections,
  CSP violations and host message arrival (tool input/result/cancel, teardown
  request); the stack's hooks mark fonts, context, start outcome and the first
  rendered answer or problem. Each report is an `[ansari-view]` console line.
- Diagnosed deployment only: MCP_VIEW_DIAGNOSTICS_ORIGIN opens connect-src to
  that one origin and adds `POST /diag/view`, which accepts a fixed report
  shape and logs it as `view.report`. Unset, the route does not exist and the
  card's permissions stay closed.
- scripts/first-load-trial.sh and first-load-timeline.mjs turn host trials and
  Railway deployment/edge logs into one timeline per trial with findings.

The browser suite found one violation on every load: zod's caught
`new Function('')` probe under the card's script-src. It is the recorded
baseline; any other error fails the check.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
yia-mw-agent
yia-mw-agent previously approved these changes Oct 29, 2026

@yia-mw-agent yia-mw-agent left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed the full merge-base-to-head diff (base develop, merge-base b1df4c7 = develop tip, 17 files, all under apps/mcp) at 1dd3ead, which is also the live head.

No material defects.

Checked:

  • exchange-log.ts / fetch-app.ts: the request body is read from a clone, so the MCP handler still gets the original; logged fields are fixed tokens (method, tool, ui:// address, client name/version/protocol), and no question, answer or parameter value reaches the log (also covered by the writeOperationLog forbidden-key filter). The response wrapper passes bytes through unchanged and reports complete, cancelled or failed exactly once.
  • Diagnostics gating: MCP_VIEW_DIAGNOSTICS_ORIGIN unset leaves the card bytes, address, closed connect-src 'none' and connectDomains unchanged and the /diag/view route absent. A bad value fails at startup. When set, exactly one origin is opened. The beacon is Host-validated, size-capped (413), parsed against a strict zod shape with free text and unknown keys dropped (400), and answers 204.
  • Card side (early script, diagnostics.ts, main.tsx): hooks only mark milestones and do not alter rendering. Reports carry marks, enumerated failures and error names only. Production cards write only a console line.
  • Scripts and README match the implemented behavior.

Validation, run locally on the exact head:

  • pnpm lint, typecheck, build, build:worker: pass.
  • pnpm test: 148/148 pass (6 new in diagnostics.test.ts).
  • pnpm test:browser: 76/76 pass, no errors.
  • CI: MCP application, frontend and gitleaks pass; api and auth were still pending at review time. Neither is touched by this diff.

Non-blocking:

  • inspectableBody reads a chunked POST with no Content-Length in full before applying the 64 KiB cap. The MCP handler enforces its own body limit, so the exposure is small.
  • /diag/view is an unauthenticated write to the logs when enabled. This is documented as Dev-only and is bounded by size and shape.

Helmet-Review-Request: #9 (comment)

Corrects measurement defects in the first-load instrumentation and scopes
it as a bounded experiment for iaser-ai#335.

- Request inspection reads a tee of the request alongside the handler, up
  to 64 KiB actually read, so a missing or wrong Content-Length can no
  longer make it read or wait for the whole body. The beacon reads at most
  8 KiB the same way and accepts 120 reports a minute per instance.
- JSON-RPC errors are decoded from JSON and SSE bodies up to 64 KiB rather
  than matched by pattern. The stream outcome is `drained`, `cancelled` or
  `failed` on this side; it does not claim delivery to the host.
- Card diagnostics run only in a diagnostic card. The early script reads an
  `ansari-diagnostics` head address and reports by itself at load, pagehide
  and timeout, so a bundle that never runs is still reported. The closed
  card's early script does nothing and writes no console line.
- `view.prepared` records the served card's address, size, diagnostic state
  and connect origins; reports are logged as client-authored.
- Trials record the deployment release and the first attempt and Retry as
  separate windows. The timeline flags mixed clients, overlapping trials
  and other releases as ambiguous, and words findings as observations.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@timeleft-- timeleft-- changed the title feat(mcp): record first-load evidence on the server and in the card feat(mcp): bounded first-load diagnostics experiment for #335 Oct 29, 2026
yia-mw-agent
yia-mw-agent previously approved these changes Oct 29, 2026

@yia-mw-agent yia-mw-agent left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Helmet-Review-Request: #9 (comment)

Reviewed the full merge-base (b1df4c7) to head (bc62edf) diff against develop: 17 files under apps/mcp, 2 commits.

No material defects found.

What I checked:

  • Server exchange log (exchange-log.ts, fetch-app.ts): the request is inspected from a clone and read through a byte-bounded reader that cancels past 64 KiB regardless of Content-Length. The response wrapper is pull-based, passes bytes through unchanged, reports stream outcome once, and keeps at most 64 KiB for decoding. Request and response lines are chained on the same inspection promise, so they stay ordered and share rid. Only fixed, token-validated fields are logged, and error handling logs name and code only, never the message.
  • Beacon (view-report.ts, fetch-app.ts): it exists only when MCP_VIEW_DIAGNOSTICS_ORIGIN is set. Host validation applies. The body is bounded to 8 KiB without trusting Content-Length and rate-limited to 120 per minute. The strict schema drops unknown keys and free text, and the log marks reports clientAuthored.
  • Closed-card path: with no origin set, prepareAnswerView leaves the CSP and connectDomains unchanged, and the beacon route returns 404. The inline early script returns at once when the meta tag is absent. The origin validator (runtime-config.ts) rejects non-https (except localhost), paths, credentials, queries and fragments.
  • Diagnostic card (mcp-app-react.html, diagnostics.ts, main.tsx): hooks only add marks and do not change rendered behavior. The early script reports at load, pagehide and 15 s. mark and report are no-ops without the record.
  • Scripts: node --check and bash -n pass. The timeline words its findings as window observations and flags ambiguous windows. test-results/ is git-ignored.

Validation run at bc62edf (all exit 0): lint, typecheck, Node build, Worker build, server tests 151/151, browser checks 78/78 (includes closed-cards-silent, load/ready/result reports accepted by the server parser, and a never-parsing bundle still reporting). PR CI checks (api, MCP application, auth, frontend, gitleaks) are all SUCCESS at this head.

Non-blocking notes:

  • This is an explicitly temporary experiment. Remove or narrow it after the trials, as the PR says.
  • finish() in observeResponse runs only when the stream ends. A request that throws inside mcp.fetch before returning a response (for example a rejected clone) gets a mcp.error but no mcp.response line. That is acceptable for this purpose.
  • No actual-host trial was run, and none could be; the host-level questions in iaser-ai#335 remain open by design.

Every operation record now carries a level: error (mcp.error, source.error),
warn (rejected or rate-limited card reports), info (startup, mcp.request,
source.start, source.complete) or debug (the first-load measurement records).

MCP_LOG_LEVEL selects info (default) or debug; a diagnostic card implies debug
and contradicting it stops startup. At info the server neither inspects nor
wraps an exchange and writes the same records as before this experiment, plus
the level and error names and codes. The inspected request summary moves from
mcp.request to a separate debug mcp.rpc record, so dropping debug lines from a
measured deployment leaves exactly the unmeasured records; a test checks this
and fails when measuring is forced on.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
yia-mw-agent
yia-mw-agent previously approved these changes Oct 30, 2026

@yia-mw-agent yia-mw-agent left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Helmet-Review-Request: #9 (comment)

Reviewed the full merge-base-to-head diff (base develop, merge-base b1df4c7, 21 files under apps/mcp) at 734d1b3, which was the live head when I started and again before submitting. No material defects found.

Validation at this head, run in a fresh worktree (pnpm install --frozen-lockfile, then in apps/mcp):

  • lint, typecheck, build and build:worker all pass.
  • test: 154/154 pass.
  • test:browser: 78 checks, errors: [].
  • The gitleaks and frontend CI checks pass. The api, auth and MCP application jobs were still pending when I checked, so the Captain should confirm them before merging.

What I checked:

  • Log levels. Every OperationRecord now carries a level, and all call sites are updated (create-server.ts, node/index.ts, fetch-app.ts). At info the /mcp handler is mcp.fetch(c.req.raw) with no clone and no wrapper. Request inspection and response wrapping happen only when measuring.
  • runtime-config.ts. MCP_LOG_LEVEL rejects any value other than info or debug. info together with MCP_VIEW_DIAGNOSTICS_ORIGIN is a startup error. A diagnostic card implies debug. The origin validator accepts only a bare https origin, or a local http one.
  • exchange-log.ts. inspectRequest clones the request before the handler reads it and reads the copy with a hard byte bound; an over-limit body is cancelled and recorded as oversize. observeResponse passes the stream through unchanged, reports once, and keeps at most 64 KiB for decoding a JSON-RPC error. Only the method, a validated ui:// URI, clientInfo name and version, the protocol version and the tool name are extracted. Everything else is dropped by token validation, and FORBIDDEN keys are stripped as before.
  • /diag/view beacon. It is registered only when the origin is configured. It is bounded to 8 KiB and 120 reports a minute, and parsed against a closed zod shape. Free text is normalised to other, and the log line is marked clientAuthored.
  • view-artifact.ts. The CSP is opened to exactly one origin, and the code throws if the closed connect-src 'none' rule or <head> is missing. The origin is validated, so the string replacement is safe. Without the origin, the card bytes and permissions are unchanged.
  • Card early script. It returns at once without the meta tag. Reporting is wrapped so it cannot disturb the card, and it reports from load, pagehide and a 15 s timeout. diagnostics.ts and the main.tsx hooks do nothing without the record and do not change what is rendered.
  • Scripts and README. first-load-trial.sh and first-load-timeline.mjs match what the README says. They attribute records by time only, flag ambiguous windows, and phrase findings as observations. test-results/ is git-ignored.

Non-blocking observations:

  • watchStart attaches handlers to running.ready in every card, including the closed one. A rejection of that promise is therefore now handled silently instead of surfacing as an unhandled rejection in the console. This does not change what the card shows, but the "closed card does nothing" claim is slightly broader than the code. Consider making watchStart a no-op when no diagnostic record exists.
  • settingsFromEnv throws on a bad MCP_LOG_LEVEL. Under Workers that means each request fails until the binding is fixed. That seems acceptable for a Dev-only experiment.
  • The PR text says the hosts have not yet been trialled and verify-container.sh was not run. Neither is part of this review.

Verdict: APPROVE. The Captain owns the merge decision.

watchStart attached handlers to the start promise in every card, so a closed
card's start failure was handled silently instead of surfacing as an unhandled
rejection, as it does without diagnostics. The closed card is the trials'
baseline, so it now attaches nothing when no diagnostic record exists.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@yia-mw-agent yia-mw-agent left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Helmet-Review-Request: #9 (comment)

Reviewed the full diff at 5851677 (base develop, merge-base b1df4c7, 21 files under apps/mcp). This is also the live head at start and at submission. No material defects.

What I covered

  • Log levels: every record carries a level. At the default info the exchange is passed straight to mcp.fetch with no inspection or wrapping, so the operational records are unchanged apart from the added level and error names/codes. The debug records are gated by one check in log.
  • Request inspection (exchange-log.ts): it reads a clone, bounded to 64 KiB regardless of Content-Length, never rejects, and records oversize or unread rather than touching the exchange. Only fixed fields are kept: tokens matching a pattern, the ui:// URI, client name, version and protocol, and the tool name. No parameter values are logged.
  • Response observation: bytes are counted and passed through unchanged, with the stream outcome (drained, cancelled or failed) reported once. Decoding is limited to 64 KiB and copes with SSE and JSON.
  • Beacon: the route exists only when a diagnostics origin is set, with host validation, an 8 KiB cap, 120 reports a minute per instance, a strict zod shape, and error messages and free text dropped. Lines are marked clientAuthored. A wildcard CORS header is acceptable for a write-only, bounded, unauthenticated endpoint that is documented as untrusted.
  • Config: MCP_VIEW_DIAGNOSTICS_ORIGIN must be a bare https origin (http only on localhost). MCP_LOG_LEVEL=info combined with a diagnostic card fails at startup, so reports cannot be silently dropped.
  • Card: with no diagnostics address the early script returns immediately and the closed card keeps its connect-src 'none'. The diagnostic card changes its bytes, URI and connect origin, and the PR says so.
  • Increment since my previous review (734d1b3 to 5851677, view/diagnostics.ts): watchStart now attaches nothing in a closed card. This restores the base behaviour, where startFaithfulCardApp had no handler on ready. In the diagnostic card it behaves as before.
  • Scripts: the trial script and the timeline tool are operator tooling, are not shipped in the server or card, and show no injection risk on read-through.

Validation, run in the worktree at this head

  • pnpm lint, typecheck, build and build:worker all pass.
  • pnpm test: 154/154 pass.
  • pnpm test:browser: 78 checks pass with no errors. This covers silent closed cards, load/ready/result reports accepted by the server's parser, and a bundle that fails to parse still reporting.

Non-blocking

  • The PR states the experiment is meant to be removed or narrowed after the trials; keeping that follow-up tracked on iaser-ai#335 would help.

@timeleft--
timeleft-- merged commit 396b091 into develop Oct 30, 2026
5 checks passed
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.

2 participants