Skip to content

Commit 96b5cc8

Browse files
committed
Inline handler logging and trim the docs
Log at the two handler sites directly instead of through a shared helper: the tool site checks for ToolError, the resource site only has to ask whether it caught an UnexpectedResourceError. Drop the three transport-matrix logging tests and their requirement ids from the interaction suite, which is for wire behaviour; the same properties are covered next to MCPServer in test_server.py. Shorten the logging docs to a pointer, reword the handling-errors section plainly, and drop the recap bullet and prompt caveats.
1 parent ff178c7 commit 96b5cc8

13 files changed

Lines changed: 39 additions & 168 deletions

File tree

docs/handlers/logging.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -70,7 +70,7 @@ went to standard error: the terminal, not the wire.
7070
don't want log lines, you want spans. Your server already emits them: the SDK traces every
7171
message with OpenTelemetry out of the box. See **[OpenTelemetry](../run/opentelemetry.md)**.
7272

73-
You don't have to log your own handlers' crashes either. When a tool or resource function raises something unexpected, the SDK writes the `ERROR` record with the traceback for you, on its own `mcp.*` loggers; a failure you raised deliberately (`ToolError`, `ResourceNotFoundError`) is an `INFO` line instead. A prompt function that raises is an `ERROR` record too, whatever it raised. **[Handling errors](../servers/handling-errors.md#what-lands-in-your-log)** has the split. (In a test using `Client(mcp, raise_exceptions=True)`, a prompt failure is handed to your test as the exception rather than logged.)
73+
You also don't need a `try`/`except` in every handler just to record failures. When a tool or resource function raises, the SDK logs it for you. **[Handling errors](../servers/handling-errors.md#what-the-server-logs)** explains what gets logged and at which level.
7474

7575
## Recap
7676

docs/servers/handling-errors.md

Lines changed: 8 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -118,26 +118,24 @@ It means a whole class of `raise` statements you don't write: don't re-validate
118118
Everything so far is what a **client** sees, and the in-memory `Client` you'll write tests
119119
with sees exactly the same thing. Even `raise_exceptions=True` doesn't hand a failing tool's
120120
exception back to the caller: by the time that flag could act, your exception is already the
121-
`is_error=True` result. Assert on the result; the traceback is in the server's log (next
122-
section), which pytest's `caplog` captures. **[Testing](../get-started/testing.md)** covers the pattern.
121+
`is_error=True` result. Assert on the result. If you need the traceback, it is in the server's
122+
log (next section), and pytest's `caplog` captures it. **[Testing](../get-started/testing.md)** covers the pattern.
123123

124-
## What lands in your log
124+
## What the server logs
125125

126-
Your server keeps its own record of these failures, and it draws one more line: between a failure you anticipated and one you didn't.
126+
The server also logs these failures, and how it logs them depends on whether you anticipated the failure.
127127

128-
`get_author` raised a plain `ValueError`. The model got the message, but the SDK can't know you *meant* that exception, so it assumes you didn't: the call is logged at `ERROR` with the full traceback. That is exactly what you want on the day the exception is a `KeyError` from three libraries down and the result text says only `'id'`.
128+
`get_author` raised a plain `ValueError`. The model got the message, but the SDK can't tell that you raised it on purpose, so it treats the call as a crash and logs it at `ERROR` with the full traceback. That is what you want on the day the exception is a `KeyError` from deep inside a library and the result text says only `'id'`.
129129

130130
When the failure is one you planned for, say so with `ToolError`:
131131

132132
```python title="server.py" hl_lines="2 12-13"
133133
--8<-- "docs_src/handling_errors/tutorial004.py"
134134
```
135135

136-
The model reads precisely what it read before. The difference is on your side: a `ToolError` is logged as one `INFO` line with no traceback, so a production log at `WARNING` stays quiet until something is actually broken. Bad arguments and unknown tool names are `INFO` lines too; those are the caller's mistakes, not yours.
136+
`ToolError` comes from `mcp.server.mcpserver.exceptions`. The model reads exactly what it read before. The difference is in your log, where a `ToolError` is a single `INFO` line with no traceback, so a production log at `WARNING` stays quiet until something is actually broken. Bad arguments and unknown tool names are logged at `INFO` too, because those are the caller's mistakes rather than yours.
137137

138-
Resources draw the same line. The `-32603` from a crashing resource handler names only the URI, so the `ERROR` record in your log is the one place the cause and its traceback exist. `ResourceNotFoundError`, including the SDK's own `Unknown resource`, is an `INFO` line. (A template parameter that fails its type annotation, `books://{id}` read with an `id` that isn't an `int`, currently counts as a crash.)
139-
140-
Prompts aren't split yet: any failure in a prompt function, including an unknown name or a missing argument, is one `ERROR` record with its traceback, written by the transport layer that turns it into the JSON-RPC error.
138+
Resources work the same way. A crashing resource handler is logged at `ERROR` with its traceback, which matters more here because the `-32603` the client receives names only the URI. `ResourceNotFoundError` is an `INFO` line.
141139

142140
## Recap
143141

@@ -146,8 +144,7 @@ Prompts aren't split yet: any failure in a prompt function, including an unknown
146144
* The deciding question: *could a smarter model have avoided this?* Yes -> exception. No -> `MCPError`.
147145
* `ResourceNotFoundError` from a resource handler -> the protocol's `-32602`, with the URI in `data`.
148146
* Bad arguments are rejected against the schema before your function runs; you don't `raise` for those.
149-
* In your log: an exception you didn't raise as `ToolError` is an `ERROR` record with its traceback; `ToolError`, bad tool arguments, unknown tool names, and `ResourceNotFoundError` are one `INFO` line each.
150-
* `from mcp import MCPError`; `ToolError` and `ResourceNotFoundError` come from `mcp.server.mcpserver.exceptions`; the error-code constants come from `mcp.types`.
147+
* `from mcp import MCPError`; the error-code constants come from `mcp.types`.
151148

152149
Errors handled. That is everything a server *exposes*. What every handler can read, and do back to the client while it runs, is the next section: **[Inside your handler](../handlers/index.md)**.
153150

docs/servers/uri-templates.md

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -201,9 +201,8 @@ These checks are a heuristic pre-filter; for filesystem access,
201201
!!! tip
202202
If your handler can't fulfil the request (the file doesn't exist, the id is unknown), raise
203203
`ResourceNotFoundError` from `mcp.server.mcpserver.exceptions`. The client gets `-32602` with
204-
your message and the URI, and your log gets one `INFO` line; any other exception is treated as
205-
a crash (`-32603`, and an `ERROR` record with the traceback). See
206-
**[Handling errors](handling-errors.md#a-resource-that-doesnt-exist)**.
204+
your message and the URI. Any other exception is treated as a crash and the client gets a
205+
generic `-32603`. See **[Handling errors](handling-errors.md#a-resource-that-doesnt-exist)**.
207206

208207
## Resources on the low-level Server
209208

docs/troubleshooting.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,7 @@ result.structured_content # None
9292

9393
The fix is in your client: **check `result.is_error`**. A `try/except` around `call_tool` catches none of these, because there is nothing to catch. This is deliberate, and it is the single most useful thing on this page to internalise: the *model* chose the call, so the model gets the message and a chance to try again. **[Handling errors](servers/handling-errors.md)** is the whole story, including the `MCPError` path that *does* raise.
9494

95-
If `<message>` alone doesn't tell you what broke, the traceback is in the **server's log**: an exception the tool didn't raise as `ToolError` is logged there at `ERROR`, as `Tool '<name>' raised an unexpected exception`.
95+
If `<message>` alone doesn't tell you what broke, look in the **server's log**. Unless the tool raised `ToolError`, the exception is logged there at `ERROR` with its traceback, as `Tool '<name>' raised an unexpected exception`.
9696

9797
## `TypeError: The @tool decorator was used incorrectly. Did you forget to call it? Use @tool() instead of @tool`
9898

src/mcp/server/mcpserver/exceptions.py

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -16,8 +16,8 @@ class ResourceError(MCPServerError):
1616
class ResourceNotFoundError(ResourceError):
1717
"""Resource does not exist.
1818
19-
Raise this from a resource handler to signal that the requested instance does not exist;
20-
clients receive `-32602` (invalid params) per
19+
Raise this from a resource handler to signal that the requested instance does not exist.
20+
Clients receive `-32602` (invalid params) per
2121
[SEP-2164](https://github.com/modelcontextprotocol/modelcontextprotocol/pull/2164).
2222
"""
2323

@@ -26,7 +26,7 @@ class UnexpectedResourceError(ResourceError):
2626
"""A resource read failed with something other than `ResourceError` or `MCPError`.
2727
2828
MCPServer raises this itself, around a crash in a resource or resource
29-
template handler or a failed file read; you never raise it. `__cause__` is
29+
template handler or a failed file read. You never raise it. `__cause__` is
3030
the original exception, which the server logs with its traceback. The
3131
message names only the URI, so the original text is withheld from the client.
3232
"""
@@ -50,7 +50,7 @@ class UnexpectedToolError(ToolError):
5050
"""A tool call failed with something other than `ToolError` or `MCPError`.
5151
5252
MCPServer raises this itself, around a crash in the tool (or a resolver) or a
53-
return value that fails output conversion; you never raise it. `__cause__` is
53+
return value that fails output conversion. You never raise it. `__cause__` is
5454
the original exception, which the server logs with its traceback before
5555
returning the usual `is_error=True` result. Catch it around
5656
`MCPServer.call_tool()` to tell a crash from a deliberate `ToolError`.

src/mcp/server/mcpserver/resources/templates.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -217,7 +217,7 @@ async def create_resource(
217217
Raises:
218218
ResourceError: If the template function raises `ResourceError`.
219219
UnexpectedResourceError: If the template function raises anything other
220-
than `ResourceError` or `MCPError`; `__cause__` is the original.
220+
than `ResourceError` or `MCPError`. `__cause__` is the original exception.
221221
"""
222222
try:
223223
# Add context to params if needed

src/mcp/server/mcpserver/resources/types.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -84,7 +84,7 @@ async def read(self) -> str | bytes:
8484
8585
Raises:
8686
UnexpectedResourceError: If the function raises anything other than
87-
`ResourceError` or `MCPError`; `__cause__` is the original.
87+
`ResourceError` or `MCPError`. `__cause__` is the original exception.
8888
"""
8989
try:
9090
fn = self.fn

src/mcp/server/mcpserver/server.py

Lines changed: 19 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -427,7 +427,14 @@ async def _handle_call_tool(
427427
except MCPError:
428428
raise
429429
except Exception as exc:
430-
_log_handler_exception("Tool", params.name, exc)
430+
# A ToolError (deliberate, unknown tool, rejected arguments) is an outcome
431+
# the model already reads in full, so it is one INFO record, repr-quoted to
432+
# keep peer-supplied text on one line. Anything else is a crash in the
433+
# tool: log the traceback that the result text doesn't carry.
434+
if isinstance(exc, ToolError) and not isinstance(exc, UnexpectedToolError):
435+
logger.info("Tool %r failed: %r", params.name, str(exc))
436+
else:
437+
logger.exception("Tool %r raised an unexpected exception", params.name)
431438
return CallToolResult(content=[TextContent(type="text", text=str(exc))], is_error=True)
432439

433440
async def _handle_list_resources(
@@ -442,7 +449,13 @@ async def _handle_read_resource(
442449
try:
443450
results = await self.read_resource(params.uri, context)
444451
except ResourceError as err:
445-
_log_handler_exception("Resource", str(params.uri), err)
452+
# UnexpectedResourceError wraps a crash whose text is withheld from the
453+
# client, so the traceback goes to the log. Any other ResourceError was
454+
# raised on purpose (or is the SDK's "Unknown resource") and is one INFO record.
455+
if isinstance(err, UnexpectedResourceError):
456+
logger.exception("Resource %r raised an unexpected exception", str(params.uri))
457+
else:
458+
logger.info("Resource %r failed: %r", str(params.uri), str(err))
446459
code = INVALID_PARAMS if isinstance(err, ResourceNotFoundError) else INTERNAL_ERROR
447460
raise MCPError(code=code, message=str(err), data={"uri": str(params.uri)})
448461
if isinstance(results, InputRequiredResult):
@@ -511,8 +524,8 @@ async def call_tool(
511524
ToolError: If the tool is unknown, the arguments fail validation, or the
512525
tool (or a resolver) raises `ToolError`.
513526
UnexpectedToolError: If the tool (or a resolver) raises anything other than
514-
`ToolError` or `MCPError`, or its return value fails output conversion;
515-
`__cause__` is the original.
527+
`ToolError` or `MCPError`, or its return value fails output conversion.
528+
`__cause__` is the original exception.
516529
"""
517530
if context is None:
518531
context = Context(mcp_server=self, subscriptions=self._subscriptions)
@@ -566,8 +579,8 @@ async def read_resource(
566579
ResourceNotFoundError: If no resource or template matches the URI.
567580
ResourceError: If the resource or template function raises `ResourceError`.
568581
UnexpectedResourceError: If reading the resource (or creating it from a
569-
template) raises anything other than `ResourceError` or `MCPError`;
570-
`__cause__` is the original.
582+
template) raises anything other than `ResourceError` or `MCPError`.
583+
`__cause__` is the original exception.
571584
"""
572585
if context is None:
573586
context = Context(mcp_server=self, subscriptions=self._subscriptions)
@@ -1320,25 +1333,6 @@ async def get_prompt(
13201333
raise ValueError(str(e)) from e
13211334

13221335

1323-
def _log_handler_exception(kind: Literal["Tool", "Resource"], name: str, exc: Exception) -> None:
1324-
"""Record a tool or resource handler failure; the one place MCPServer logs them.
1325-
1326-
Called from the `except` block that turns the failure into a response. A
1327-
`ToolError` or `ResourceError` (deliberate, an unknown name, arguments that
1328-
failed validation, `ResourceNotFoundError`) is an anticipated outcome the
1329-
client already receives in full: one INFO record, no traceback, the text
1330-
repr-quoted so peer-supplied names and newlines stay on one line. Anything
1331-
else, including the `Unexpected*` wrappers whose `__cause__` is what the
1332-
handler actually raised, is a crash in user code: ERROR with the traceback.
1333-
"""
1334-
if isinstance(exc, ToolError | ResourceError) and not isinstance(
1335-
exc, UnexpectedToolError | UnexpectedResourceError
1336-
):
1337-
logger.info("%s %r failed: %r", kind, name, str(exc))
1338-
else:
1339-
logger.exception("%s %r raised an unexpected exception", kind, name, exc_info=exc)
1340-
1341-
13421336
def _version_gated(method: MethodBinding) -> RequestHandler:
13431337
"""Wrap a method handler so a request at a disallowed protocol version is rejected.
13441338

tests/docs_src/test_handling_errors.py

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -90,7 +90,7 @@ async def test_a_title_the_template_knows_reads_normally() -> None:
9090

9191

9292
async def test_a_plain_exception_is_logged_as_a_crash_with_its_traceback(caplog: pytest.LogCaptureFixture) -> None:
93-
"""tutorial001, "What lands in your log": the `ValueError` is one ERROR record carrying the traceback."""
93+
"""tutorial001, "What the server logs": the `ValueError` is one ERROR record carrying the traceback."""
9494
caplog.set_level(logging.INFO)
9595
async with Client(tutorial001.mcp) as client:
9696
await client.call_tool("get_author", {"title": "Nothing"})
@@ -99,7 +99,6 @@ async def test_a_plain_exception_is_logged_as_a_crash_with_its_traceback(caplog:
9999
assert record.exc_info is not None
100100
logged = record.exc_info[1]
101101
assert logged is not None and isinstance(logged.__cause__, ValueError)
102-
assert str(logged.__cause__) == "No book titled 'Nothing' in the catalog."
103102

104103

105104
async def test_tool_error_reads_the_same_to_the_model_and_logs_one_info_line(
@@ -119,7 +118,7 @@ async def test_tool_error_reads_the_same_to_the_model_and_logs_one_info_line(
119118

120119

121120
async def test_a_bad_argument_is_an_info_line_not_a_crash(caplog: pytest.LogCaptureFixture) -> None:
122-
""" "What lands in your log": schema rejection of the arguments is logged at INFO with no traceback."""
121+
""" "What the server logs": schema rejection of the arguments is logged at INFO with no traceback."""
123122
caplog.set_level(logging.INFO)
124123
async with Client(tutorial001.mcp) as client:
125124
result = await client.call_tool("get_author", {"title": 42})

tests/interaction/_requirements.py

Lines changed: 0 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -1020,14 +1020,6 @@ def __post_init__(self) -> None:
10201020
"tool result with isError true and the failure text in content; it does not become a JSON-RPC error."
10211021
),
10221022
),
1023-
"mcpserver:tool:handler-throws:logged": Requirement(
1024-
source="sdk",
1025-
behavior=(
1026-
"An exception other than ToolError raised by a tool function is logged server-side exactly once, "
1027-
"at ERROR with its traceback, before the isError result is returned; the transport does not change "
1028-
"how many records are written."
1029-
),
1030-
),
10311023
"mcpserver:tool:input-validation": Requirement(
10321024
source=f"{SPEC_BASE_URL}/server/tools#error-handling",
10331025
behavior=(
@@ -1319,13 +1311,6 @@ def __post_init__(self) -> None:
13191311
"(-32603 Internal error), with the original exception text withheld."
13201312
),
13211313
),
1322-
"mcpserver:resource:read-throws:logged": Requirement(
1323-
source="sdk",
1324-
behavior=(
1325-
"The exception withheld from the -32603 response is logged server-side exactly once, at ERROR "
1326-
"with its traceback; the transport does not change how many records are written."
1327-
),
1328-
),
13291314
"mcpserver:resource:static": Requirement(
13301315
source="sdk",
13311316
behavior=(
@@ -1442,14 +1427,6 @@ def __post_init__(self) -> None:
14421427
source="sdk",
14431428
behavior="A prompt with optional arguments can be fetched without supplying them.",
14441429
),
1445-
"mcpserver:prompt:render-throws:logged": Requirement(
1446-
source="sdk",
1447-
behavior=(
1448-
"An exception raised by a prompt function is logged server-side exactly once, at ERROR with its "
1449-
"traceback, by whichever layer turns it into the JSON-RPC error; the transport does not change how "
1450-
"many records are written."
1451-
),
1452-
),
14531430
"mcpserver:prompt:unknown-name": Requirement(
14541431
source=f"{SPEC_BASE_URL}/server/prompts#error-handling",
14551432
behavior="prompts/get for a name that was never registered returns JSON-RPC error -32602 (Invalid params).",

0 commit comments

Comments
 (0)