Skip to content

Commit 65c96bf

Browse files
committed
Record post-chain result failures on the OpenTelemetry span
The context-tier OpenTelemetryMiddleware closes its span when the middleware chain returns, but result dumping and spec-result serialization ran after that in _on_request. A handler returning an unsupported type or a malformed dict for a spec method surfaced as a JSON-RPC error to the client while the span finished UNSET with no error attributes, so default error-rate dashboards missed the failure. Move dumping and serialization into the chain (a new _serialize helper called from _inner) so the span observes these failures. Serializing inside the chain also lets a middleware short-circuit own its result shape directly, replacing the post-chain KeyError catch. Also point the SEP-414 doc link at its spec-repo PR rather than the repository root.
1 parent 051f271 commit 65c96bf

3 files changed

Lines changed: 52 additions & 19 deletions

File tree

docs/advanced/opentelemetry.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,7 @@ connected picture.
6868
When the client and the server both run the SDK, that connection is automatic. The client injects
6969
the [W3C trace context](https://www.w3.org/TR/trace-context/) into the request, and the server
7070
reads it back out, so the server span nests under the client span in the same trace. This is
71-
[SEP-414](https://github.com/modelcontextprotocol/modelcontextprotocol), and you get it without
71+
[SEP-414](https://github.com/modelcontextprotocol/modelcontextprotocol/pull/414), and you get it without
7272
asking.
7373

7474
If the inbound message carries no trace context, for example a request from a client that is not

src/mcp/server/runner.py

Lines changed: 28 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -171,7 +171,6 @@ async def _on_request(
171171
meta = _extract_meta(params)
172172
version = self.connection.protocol_version
173173
ctx = self._make_context(dctx, method, params, meta, version)
174-
is_spec_method = method in _methods.SPEC_CLIENT_METHODS
175174

176175
async def _inner(ctx: ServerRequestContext[LifespanT, Any]) -> HandlerResult:
177176
# Read method/params off `ctx` so a middleware that rewrote them via
@@ -190,7 +189,7 @@ async def _inner(ctx: ServerRequestContext[LifespanT, Any]) -> HandlerResult:
190189
# the gate become a per-version legacy path then. Initialize runs inline
191190
# (read loop parked), so awaiting the peer anywhere on this path deadlocks.
192191
if method == "initialize":
193-
return self._handle_initialize(params)
192+
return self._serialize(method, version, self._handle_initialize(params))
194193
# Methods without a handler are METHOD_NOT_FOUND regardless of
195194
# initialization state: JSON-RPC 2.0 reserves -32601 for "not
196195
# available on this server", and clients probing a server before
@@ -209,25 +208,14 @@ async def _inner(ctx: ServerRequestContext[LifespanT, Any]) -> HandlerResult:
209208
if isinstance(result, ErrorData):
210209
# Raise inside the chain so middleware observes the failure.
211210
raise MCPError.from_error_data(result)
212-
return result
211+
# Dump and serialize inside the chain so the OpenTelemetry span (the
212+
# outermost middleware) records a failing handler return shape too.
213+
return self._serialize(method, version, result)
213214

214215
call = self._compose_server_middleware(_inner)
216+
# `_inner` already produced the wire dict; a middleware that short-circuited
217+
# without `call_next` is trusted to return its own well-formed result.
215218
result = _dump_result(await call(ctx))
216-
# TODO(L56): reject resultType values outside {"complete", "input_required"} unless the
217-
# corresponding extension is in this request's _meta clientCapabilities.extensions; the
218-
# explicit MUST-reject is client-side (basic/index.mdx ResultType), this enforces it proactively.
219-
if is_spec_method:
220-
try:
221-
result = _methods.serialize_server_result(method, version, result)
222-
except KeyError:
223-
# Middleware short-circuited a wrong-version spec method without
224-
# calling `call_next`; it owns the result shape.
225-
pass
226-
except ValidationError:
227-
# Server bug, not client fault. Detail stays in the server log:
228-
# pydantic messages echo the result body.
229-
logger.exception("handler for %r returned an invalid result", method)
230-
raise MCPError(code=INTERNAL_ERROR, message="Handler returned an invalid result") from None
231219
if method == "initialize":
232220
# Commit only on chain success, so a middleware veto leaves no state.
233221
# Race-free: the read loop is parked until this call returns.
@@ -335,6 +323,28 @@ def _make_context(
335323
close_standalone_sse_stream=close_standalone_sse_stream,
336324
)
337325

326+
@staticmethod
327+
def _serialize(method: str, version: str, result: HandlerResult) -> dict[str, Any]:
328+
"""Dump a handler result to the wire dict, serializing spec methods.
329+
330+
Runs inside the middleware chain so the OpenTelemetry span observes a
331+
failing return shape (unsupported type, malformed spec result) as an
332+
error rather than closing on a request that the client sees fail.
333+
"""
334+
dumped = _dump_result(result)
335+
# TODO(L56): reject resultType values outside {"complete", "input_required"} unless the
336+
# corresponding extension is in this request's _meta clientCapabilities.extensions; the
337+
# explicit MUST-reject is client-side (basic/index.mdx ResultType), this enforces it proactively.
338+
if method not in _methods.SPEC_CLIENT_METHODS:
339+
return dumped
340+
try:
341+
return _methods.serialize_server_result(method, version, dumped)
342+
except ValidationError:
343+
# Server bug, not client fault. Detail stays in the server log:
344+
# pydantic messages echo the result body.
345+
logger.exception("handler for %r returned an invalid result", method)
346+
raise MCPError(code=INTERNAL_ERROR, message="Handler returned an invalid result") from None
347+
338348
@staticmethod
339349
def _negotiate_initialize(params: Mapping[str, Any] | None) -> tuple[InitializeRequestParams, str]:
340350
"""Validate `initialize` params and pick the protocol version."""

tests/server/test_otel.py

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
import anyio
1212
import pytest
1313
from mcp_types import (
14+
INTERNAL_ERROR,
1415
INVALID_PARAMS,
1516
CallToolRequestParams,
1617
CallToolResult,
@@ -297,6 +298,28 @@ async def failing(ctx: Ctx, params: PaginatedRequestParams | None) -> Any:
297298
assert event.attributes["exception.type"] == "ValueError"
298299

299300

301+
@pytest.mark.anyio
302+
async def test_records_error_status_on_malformed_spec_result(server: SrvT, spans: SpanCapture):
303+
"""Result serialization runs inside the span, so a handler returning a
304+
malformed dict for a spec method (INTERNAL_ERROR on the wire) is recorded
305+
on the span rather than closing it as a success."""
306+
307+
async def bad_result(ctx: Ctx, params: PaginatedRequestParams | None) -> dict[str, Any]:
308+
return {"tools": 42}
309+
310+
server.add_request_handler("tools/list", PaginatedRequestParams, bad_result)
311+
async with connected_runner(server) as (client, _):
312+
spans.clear()
313+
with pytest.raises(MCPError) as exc:
314+
await client.send_raw_request("tools/list", None)
315+
assert exc.value.error.code == INTERNAL_ERROR
316+
[span] = [s for s in spans.finished() if s.kind == SpanKind.SERVER]
317+
assert span.status.status_code == StatusCode.ERROR
318+
assert span.attributes is not None
319+
assert span.attributes["error.type"] == str(INTERNAL_ERROR)
320+
assert span.attributes["rpc.response.status_code"] == str(INTERNAL_ERROR)
321+
322+
300323
@pytest.mark.anyio
301324
async def test_passes_rewritten_context_through(server: SrvT, spans: SpanCapture):
302325
seen_arguments: dict[str, Any] = {}

0 commit comments

Comments
 (0)