chore: filter upstream MCP-SDK race-condition log noise on session teardown

src/logging_filters.py

@@ -0,0 +1,53 @@
+"""Logging filters used by ``server._run`` to mute known-benign upstream noise.
+
+These filters are pure log hygiene — they neither change behaviour nor mask
+real errors, only drop specific records the operator can do nothing useful
+with. Each filter is scoped to a single logger and a single record shape.
+"""
+
+from __future__ import annotations
+
+import logging
+
+import anyio
+
+
+class StandaloneSseWriterRaceFilter(logging.Filter):
+    """Drop the ``mcp.server.streamable_http`` ERROR record that fires on
+    session teardown when ``GET /mcp`` SSE writers race against ``DELETE
+    /mcp`` cleanup.
+
+    The upstream MCP SDK logs a full ``ClosedResourceError`` traceback from
+    ``standalone_sse_writer`` (around line 711 of
+    ``mcp/server/streamable_http.py``) every time a stateful client opens an
+    SSE stream and immediately terminates the session — which, for our
+    LiteLLM-fronted setup, is every brokered call. The DELETE itself returns
+    200, the session ends cleanly, the client gets its response; the trace
+    is purely log noise.
+
+    Upstream PR #1384 (merged 2025-12-04) added explicit
+    ``ClosedResourceError`` handling to the sibling ``message_router``. The
+    same pattern hasn't been ported to ``standalone_sse_writer`` yet, so we
+    filter the record locally rather than crank the whole logger to
+    ``CRITICAL``.
+
+    Filter is intentionally narrow: only drops records whose exact message
+    matches and whose ``exc_info`` is an ``anyio.ClosedResourceError`` (or
+    subclass). Every other ERROR from the same logger — including legitimate
+    streamable-HTTP failures — passes through unchanged.
+    """
+
+    _MESSAGE = "Error in standalone SSE writer"
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        if record.getMessage() != self._MESSAGE:
+            return True
+        if not record.exc_info:
+            return True
+        exc_type = record.exc_info[0]
+        if exc_type is None:
+            return True
+        try:
+            return not issubclass(exc_type, anyio.ClosedResourceError)
+        except TypeError:
+            return True

src/server.py

@@ -488,6 +488,14 @@ def _run(transport: str) -> None:
     import uvicorn
 
     from src.auth import BearerAuthMiddleware
+    from src.logging_filters import StandaloneSseWriterRaceFilter
+
+    # Mute the upstream SDK's ClosedResourceError noise on session teardown.
+    # See StandaloneSseWriterRaceFilter for why this is benign and narrow.
+    # Idempotent: re-entry into _run (eg. tests) doesn't stack duplicate filters.
+    sdk_logger = logging.getLogger("mcp.server.streamable_http")
+    if not any(isinstance(f, StandaloneSseWriterRaceFilter) for f in sdk_logger.filters):
+        sdk_logger.addFilter(StandaloneSseWriterRaceFilter())
 
     app = mcp.streamable_http_app() if transport == "streamable-http" else mcp.sse_app()
 

tests/test_logging_filters.py

@@ -0,0 +1,92 @@
+"""Tests for ``src.logging_filters.StandaloneSseWriterRaceFilter``."""
+
+from __future__ import annotations
+
+import logging
+import sys
+
+import anyio
+import pytest
+
+from src.logging_filters import StandaloneSseWriterRaceFilter
+
+
+def _make_record(
+    message: str,
+    *,
+    exc_info: tuple | None = None,
+) -> logging.LogRecord:
+    return logging.LogRecord(
+        name="mcp.server.streamable_http",
+        level=logging.ERROR,
+        pathname=__file__,
+        lineno=0,
+        msg=message,
+        args=(),
+        exc_info=exc_info,
+    )
+
+
+def _exc_info_for(exc: BaseException) -> tuple:
+    try:
+        raise exc
+    except BaseException:
+        return sys.exc_info()
+
+
+class TestStandaloneSseWriterRaceFilter:
+    def setup_method(self) -> None:
+        self.filt = StandaloneSseWriterRaceFilter()
+
+    def test_passes_unrelated_message(self) -> None:
+        rec = _make_record("Some other error", exc_info=_exc_info_for(anyio.ClosedResourceError()))
+        assert self.filt.filter(rec) is True
+
+    def test_passes_target_message_without_exc_info(self) -> None:
+        rec = _make_record("Error in standalone SSE writer")
+        assert self.filt.filter(rec) is True
+
+    def test_passes_target_message_with_unrelated_exc(self) -> None:
+        rec = _make_record(
+            "Error in standalone SSE writer",
+            exc_info=_exc_info_for(RuntimeError("totally different")),
+        )
+        assert self.filt.filter(rec) is True
+
+    def test_drops_target_message_with_closed_resource_error(self) -> None:
+        rec = _make_record(
+            "Error in standalone SSE writer",
+            exc_info=_exc_info_for(anyio.ClosedResourceError()),
+        )
+        assert self.filt.filter(rec) is False
+
+    def test_drops_subclass_of_closed_resource_error(self) -> None:
+        class _SubError(anyio.ClosedResourceError):
+            pass
+
+        rec = _make_record(
+            "Error in standalone SSE writer",
+            exc_info=_exc_info_for(_SubError()),
+        )
+        assert self.filt.filter(rec) is False
+
+    def test_handles_malformed_exc_info_gracefully(self) -> None:
+        """exc_info[0] = None can happen on some logging shapes — must not raise."""
+        rec = _make_record("Error in standalone SSE writer", exc_info=(None, None, None))
+        assert self.filt.filter(rec) is True
+
+
+@pytest.mark.parametrize(
+    "msg",
+    [
+        "error in standalone sse writer",
+        "Error in standalone SSE writer (extra)",
+        "Standalone SSE writer error",
+    ],
+)
+def test_message_match_is_exact(msg: str) -> None:
+    """Filter intentionally matches only the exact upstream message string —
+    a future upstream wording change should bring the noise back, not mask it."""
+    filt = StandaloneSseWriterRaceFilter()
+    rec = _make_record(msg, exc_info=_exc_info_for(anyio.ClosedResourceError()))
+    assert filt.filter(rec) is True

tests/test_run_wiring.py

@@ -8,13 +8,15 @@
 
 from __future__ import annotations
 
+import logging
 from contextlib import contextmanager
 from unittest.mock import MagicMock, patch
 
 import pytest
 
 import src.server as server_mod
 from src.auth import BearerAuthMiddleware
+from src.logging_filters import StandaloneSseWriterRaceFilter
 
 
 def _fake_settings(*, has_token: bool, token: str = "s3cret") -> MagicMock:
@@ -100,3 +102,60 @@ def test_warns_when_token_missing(self, caplog: pytest.LogCaptureFixture) -> Non
             "MCP_BEARER_TOKEN not set" in rec.message and rec.levelname == "WARNING"
             for rec in caplog.records
         )
+
+
+@pytest.fixture
+def _clean_sdk_logger_filters():
+    """Strip our race filter from the upstream logger before + after each test
+    so order-of-execution doesn't leak attachment state across cases."""
+    sdk_logger = logging.getLogger("mcp.server.streamable_http")
+
+    def _purge() -> None:
+        for f in list(sdk_logger.filters):
+            if isinstance(f, StandaloneSseWriterRaceFilter):
+                sdk_logger.removeFilter(f)
+
+    _purge()
+    try:
+        yield sdk_logger
+    finally:
+        _purge()
+
+
+class TestRaceFilterInstallation:
+    def test_attaches_race_filter_on_http_transport(
+        self, _clean_sdk_logger_filters: logging.Logger
+    ) -> None:
+        bare_app = object()
+        with (
+            patch.object(server_mod.mcp, "streamable_http_app", return_value=bare_app),
+            patch.object(server_mod, "settings", _fake_settings(has_token=False)),
+            _patched_uvicorn(),
+        ):
+            server_mod._run("streamable-http")
+        assert any(
+            isinstance(f, StandaloneSseWriterRaceFilter) for f in _clean_sdk_logger_filters.filters
+        )
+
+    def test_does_not_attach_on_stdio(self, _clean_sdk_logger_filters: logging.Logger) -> None:
+        with _patched_uvicorn(), patch.object(server_mod.mcp, "run"):
+            server_mod._run("stdio")
+        assert not any(
+            isinstance(f, StandaloneSseWriterRaceFilter) for f in _clean_sdk_logger_filters.filters
+        )
+
+    def test_attachment_is_idempotent(self, _clean_sdk_logger_filters: logging.Logger) -> None:
+        bare_app = object()
+        with (
+            patch.object(server_mod.mcp, "streamable_http_app", return_value=bare_app),
+            patch.object(server_mod, "settings", _fake_settings(has_token=False)),
+            _patched_uvicorn(),
+        ):
+            server_mod._run("streamable-http")
+            server_mod._run("streamable-http")
+        race_filters = [
+            f
+            for f in _clean_sdk_logger_filters.filters
+            if isinstance(f, StandaloneSseWriterRaceFilter)
+        ]
+        assert len(race_filters) == 1