This is an automated email from the ASF dual-hosted git repository. eschutho pushed a commit to branch fix-mcp-client-disconnect-log-noise in repository https://gitbox.apache.org/repos/asf/superset.git
commit bae64509986188a586c2980f5c4a7191ddc7d2fc Author: Elizabeth Thompson <[email protected]> AuthorDate: Sun Jul 26 15:39:31 2026 +0000 fix(mcp_service): downgrade client-disconnect transport noise to WARNING (SC-115264) MCP client disconnects mid-request (a cancelled or timed-out tool call — normal client behavior, not a Superset bug) are logged at ERROR by the mcp SDK's own transport code, producing two separate Sentry issues from a single incident: mcp.server.streamable_http._handle_post_request logs starlette's ClientDisconnect via logger.exception(), and re-raises it into the session's read stream, where mcp.server.lowlevel.server logs it a second time via a fixed "Received exception from stream: " message (ClientDisconnect always renders as an empty string). Add MCPTransportDisconnectFilter, matching the existing pattern used for FastMCPValidationFilter, to downgrade only these two exact log patterns to WARNING so they stay visible in log aggregation without paging on Sentry. Genuine ERRORs on these loggers are untouched. Fixes SUPERSET-PYTHON-XVB Fixes SUPERSET-PYTHON-YYS Co-Authored-By: Claude <[email protected]> --- superset/mcp_service/server.py | 52 +++++++ .../unit_tests/mcp_service/test_logging_filters.py | 162 +++++++++++++++++++++ 2 files changed, 214 insertions(+) diff --git a/superset/mcp_service/server.py b/superset/mcp_service/server.py index 9d6b7a5d487..32c39443fd8 100644 --- a/superset/mcp_service/server.py +++ b/superset/mcp_service/server.py @@ -30,6 +30,7 @@ from typing import Annotated, Any, Callable import uvicorn from fastmcp.exceptions import ToolError from fastmcp.server.middleware import Middleware +from starlette.requests import ClientDisconnect from superset.mcp_service.app import create_mcp_app, init_fastmcp_server from superset.mcp_service.jwt_verifier import BrowserHelloMiddleware @@ -112,6 +113,46 @@ class FastMCPValidationFilter(logging.Filter): return True +class MCPTransportDisconnectFilter(logging.Filter): + """Downgrade MCP SDK client-disconnect transport logs from ERROR to WARNING. + + When an MCP client disconnects mid-request (a cancelled or timed-out tool + call — normal client behavior, not a Superset bug), the ``mcp`` SDK's own + transport code logs it at ERROR with a full traceback, and separately + re-raises it into the session's message loop, which logs a second ERROR. + Both are expected under normal client behavior and should not page or + open incidents; downgrading to WARNING keeps them visible in log + aggregation without polluting ERROR-level alerting. + + Two different loggers require two different matching strategies: + + - ``mcp.server.streamable_http`` (``_handle_post_request``) catches the + disconnect via a broad ``except Exception`` and logs it with + ``logger.exception(...)``, so ``record.exc_info`` carries the actual + exception object — we can check its type directly. + - ``mcp.server.lowlevel.server`` (``_handle_message``) receives the same + exception secondhand, already wrapped as a bare + ``Exception(ClientDisconnect())`` pushed onto the read stream. The + original type is lost by the time it's logged, so exception-type + checks are impossible here. ``ClientDisconnect`` is always raised with + zero args, so ``str(ClientDisconnect())`` is always ``""`` — making the + rendered message a fixed, matchable string instead. + """ + + def filter(self, record: logging.LogRecord) -> bool: + if record.levelno != logging.ERROR: + return True + if record.name == "mcp.server.streamable_http": + if record.exc_info and isinstance(record.exc_info[1], ClientDisconnect): + record.levelno = logging.WARNING + record.levelname = "WARNING" + elif record.name == "mcp.server.lowlevel.server": + if record.getMessage() == "Received exception from stream: ": + record.levelno = logging.WARNING + record.levelname = "WARNING" + return True + + def configure_logging(debug: bool = False) -> None: """Configure logging for the MCP service.""" import sys @@ -147,6 +188,17 @@ def configure_logging(debug: bool = False) -> None: fastmcp_server_logger = logging.getLogger("fastmcp.server.server") fastmcp_server_logger.addFilter(FastMCPValidationFilter()) + # MCP client disconnects (cancelled/timed-out tool calls) are logged at + # ERROR by the mcp SDK's transport and lowlevel server loggers. These are + # expected client behavior, not Superset bugs — downgrade to WARNING. + transport_disconnect_filter = MCPTransportDisconnectFilter() + logging.getLogger("mcp.server.streamable_http").addFilter( + transport_disconnect_filter + ) + logging.getLogger("mcp.server.lowlevel.server").addFilter( + transport_disconnect_filter + ) + def create_event_store(config: dict[str, Any] | None = None) -> Any | None: """ diff --git a/tests/unit_tests/mcp_service/test_logging_filters.py b/tests/unit_tests/mcp_service/test_logging_filters.py new file mode 100644 index 00000000000..7ef7e354067 --- /dev/null +++ b/tests/unit_tests/mcp_service/test_logging_filters.py @@ -0,0 +1,162 @@ +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, +# software distributed under the License is distributed on an +# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +# KIND, either express or implied. See the License for the +# specific language governing permissions and limitations +# under the License. + +""" +Unit tests for MCPTransportDisconnectFilter. + +Tests verify that: +- streamable_http ERROR records carrying a ClientDisconnect exc_info are + downgraded to WARNING +- streamable_http ERROR records carrying an unrelated exception stay at ERROR +- lowlevel.server ERROR records with the exact "Received exception from + stream: " message are downgraded to WARNING +- lowlevel.server ERROR records with a different message stay at ERROR +- records below ERROR level pass through unchanged regardless of logger name +""" + +import logging + +from starlette.requests import ClientDisconnect + +from superset.mcp_service.server import MCPTransportDisconnectFilter + + +def _make_record( + name: str, + level: int, + msg: str, + exc_info: tuple | None = None, +) -> logging.LogRecord: + return logging.getLogger(name).makeRecord( + name, level, "test_file.py", 1, msg, (), exc_info + ) + + +def _get_client_disconnect_exc_info() -> tuple: + try: + raise ClientDisconnect() + except ClientDisconnect: + import sys + + return sys.exc_info() + + +def _get_value_error_exc_info() -> tuple: + try: + raise ValueError("boom") + except ValueError: + import sys + + return sys.exc_info() + + +class TestMCPTransportDisconnectFilterStreamableHttp: + """Tests for the mcp.server.streamable_http branch of the filter.""" + + def test_client_disconnect_downgraded_to_warning(self) -> None: + record = _make_record( + "mcp.server.streamable_http", + logging.ERROR, + "Error handling POST request", + exc_info=_get_client_disconnect_exc_info(), + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.WARNING + assert record.levelname == "WARNING" + + def test_other_exception_stays_at_error(self) -> None: + record = _make_record( + "mcp.server.streamable_http", + logging.ERROR, + "Error handling POST request", + exc_info=_get_value_error_exc_info(), + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.ERROR + assert record.levelname == "ERROR" + + def test_no_exc_info_stays_at_error(self) -> None: + record = _make_record( + "mcp.server.streamable_http", + logging.ERROR, + "Error handling POST request", + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.ERROR + + +class TestMCPTransportDisconnectFilterLowlevelServer: + """Tests for the mcp.server.lowlevel.server branch of the filter.""" + + def test_empty_exception_message_downgraded_to_warning(self) -> None: + record = _make_record( + "mcp.server.lowlevel.server", + logging.ERROR, + "Received exception from stream: ", + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.WARNING + assert record.levelname == "WARNING" + + def test_different_message_stays_at_error(self) -> None: + record = _make_record( + "mcp.server.lowlevel.server", + logging.ERROR, + "Received exception from stream: something else", + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.ERROR + + def test_unrelated_message_stays_at_error(self) -> None: + record = _make_record( + "mcp.server.lowlevel.server", + logging.ERROR, + "Some unrelated error", + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.ERROR + + +class TestMCPTransportDisconnectFilterPassthrough: + """Records below ERROR level are always left unchanged.""" + + def test_warning_level_passes_through_unchanged(self) -> None: + record = _make_record( + "mcp.server.lowlevel.server", + logging.WARNING, + "Received exception from stream: ", + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.WARNING + + def test_info_level_passes_through_unchanged(self) -> None: + record = _make_record( + "mcp.server.streamable_http", + logging.INFO, + "Error handling POST request", + exc_info=_get_client_disconnect_exc_info(), + ) + + assert MCPTransportDisconnectFilter().filter(record) is True + assert record.levelno == logging.INFO
