Skip to content

mcp(observability): three telemetry blind spots the first real MCP traffic exposed #10279

Description

@JSONbored

Part of epic #8286 (Phase 3 — AI observability). Found by driving the live remote MCP at api.loopover.ai/mcp with 101 real tools/call requests on 2026-07-31 — the first genuine MCP traffic this project has ever recorded, now that POSTHOG_API_KEY is set on the loopover-api Worker.

The good news first: the surface works. initialize returns 200 (#10191 confirmed fixed in production, loopover 3.21.1, protocol 2025-06-18), tools/list advertises 130 tools, and all four canonical events now flow — $mcp_initialize, $mcp_tools_list, $mcp_tool_call and usage_event. $mcp_is_error is correct on every call it records (74 false / 5 true, matching the sweep exactly), so the existing MCP error-rate alert will fire on real failures.

Three blind spots showed up that only real traffic could reveal.

1. A schema-rejected call emits no telemetry at all

101 tools/call requests were sent; 93 produced a $mcp_tool_call. The 8 missing ones are exactly the 8 that failed the tool's inputSchema:

loopover_check_slop_risk            loopover_plan_status
loopover_compare_local_variants     loopover_record_step_result
loopover_compare_pr_variants        loopover_run_local_scorer
loopover_simulate_open_pr_pressure  loopover_suggest_boundary_tests

All returned MCP error -32602: Input validation error. The MCP SDK validates against inputSchema and rejects before the handler runs, so withMcpToolTelemetry's wrapper in src/mcp/dispatch-telemetry.ts is never entered and nothing is emitted.

This is the worst of the three, because it is silent in exactly the case you most want to see. A client whose argument shapes have drifted from the server's schemas — a stale @loopover/mcp, a hand-rolled agent, a tool whose schema tightened in a release — fails every call and the dashboards stay perfectly green. The malformed-client failure mode is invisible by construction.

2. $mcp_duration_ms is always 0 on the error path

calls zero duration max
$mcp_is_error = false 74 6 2594 ms
$mcp_is_error = true 5 5 0 ms

Every errored call reports 0, though the client measured 819–1694 ms wall clock for those same five.

The cause is not the arithmetic — src/mcp/dispatch-telemetry.ts captures startedAt at wrapper entry and computes Date.now() - startedAt on both paths. It is that Cloudflare Workers freezes Date.now() between I/O operations: the clock only advances when the isolate performs I/O. A call rejected by a permission check or an argument guard does no I/O, so both readings are the same instant and the subtraction is exactly 0 — not merely small. The 6 zero-duration successes are the same effect on tools that answer without I/O.

So the latency dimension is unusable precisely where it matters most: a timeout-bucketed failure would report 0 ms. Any fix needs a monotonic source that survives the Workers clock (performance.now(), or accepting that pure-compute paths are unmeasurable and recording null rather than a fabricated 0 — a real zero and an unmeasurable one must not be the same value).

3. A missing-argument failure is bucketed as an internal fault

Of the 5 recorded errors, the 3 credential denials classified correctly as permission. The other 2 did not:

tool message $mcp_error_type should be
loopover_explain_score_breakdown contributorLogin is required for score breakdown. internal validation
loopover_get_pr_ai_review_findings A pull-request number is required: pass 'number'. internal validation

MCP_ERROR_TYPE_BY_CODE in packages/loopover-contract/src/telemetry.ts maps invalid_input → validation correctly, so the mapping is not the bug. These two tools reject with a bare text error carrying no structured envelope, so resolveErrorCode falls back to unknown_error, which maps to internal.

The consequence is that caller mistakes land in the same bucket as genuine server faults. internal is the bucket you would alert on, and it is now permanently polluted by ordinary bad input.

Deliverables

  • Record a $mcp_tool_call for a schema-rejected tools/call, with $mcp_error_type: "validation". It has to be captured outside the per-tool wrapper, since the SDK rejects before dispatch — handleMcpRequest already inspects the JSON-RPC body for result.isError (mcp(telemetry): derive the remote request-level ok from the tool result, not the HTTP status #10035) and is the natural place to also notice a -32602.
  • Stop reporting a fabricated 0 ms. Either measure with a source that advances without I/O, or emit no duration at all when the reading is 0 and the call did no I/O — a dashboard must not average unmeasurable calls in as instant ones.
  • Give the two tools above a structured error envelope so they classify as validation, and add an invariant test that every tool's error path returns an envelope carrying a member of the closed code set.

Reproducing

The sweep is straightforward to repeat: authenticate with loopover-mcp login, then drive POST /mcp with initializenotifications/initializedtools/listtools/call per tool. Two notes for whoever does — a request must send Accept: application/json, text/event-stream, and Cloudflare rule 1010 rejects Python's default urllib User-Agent on this zone, so the client has to identify itself.

Metadata

Metadata

Assignees

Labels

No labels
No labels

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions