From 39e147785265577ec37809e8e4839d45aac0fe8c Mon Sep 17 00:00:00 2001 From: rahul188 Date: Sat, 18 Jul 2026 14:26:40 +0530 Subject: [PATCH 1/2] fix: prevent infinite warning-logging loop in _handle_message Server._handle_message logged recorded warnings while still inside the warnings.catch_warnings(record=True) block. Since record=True installs an always filter, a warning emitted by a logging handler during that logging step was appended to the list being iterated, so the loop never terminated. The loop is synchronous, so cancellation could not interrupt it and the task wedged. Snapshot the recorded warnings and log them after leaving the catch_warnings block so handler-emitted warnings can no longer extend the iteration. Github-Issue: #3122 Reported-by: fas89 --- src/mcp/server/lowlevel/server.py | 6 +- tests/issues/test_3122_warning_loop.py | 78 ++++++++++++++++++++++++++ 2 files changed, 82 insertions(+), 2 deletions(-) create mode 100644 tests/issues/test_3122_warning_loop.py diff --git a/src/mcp/server/lowlevel/server.py b/src/mcp/server/lowlevel/server.py index 25a8fde37..07a51764a 100644 --- a/src/mcp/server/lowlevel/server.py +++ b/src/mcp/server/lowlevel/server.py @@ -719,8 +719,10 @@ async def _handle_message( if raise_exceptions: raise message - for warning in w: # pragma: no cover - logger.info("Warning: %s: %s", warning.category.__name__, warning.message) + recorded_warnings = list(w) + + for warning in recorded_warnings: + logger.info("Warning: %s: %s", warning.category.__name__, warning.message) async def _handle_request( self, diff --git a/tests/issues/test_3122_warning_loop.py b/tests/issues/test_3122_warning_loop.py new file mode 100644 index 000000000..6c1624b71 --- /dev/null +++ b/tests/issues/test_3122_warning_loop.py @@ -0,0 +1,78 @@ +"""Regression test for #3122. + +``Server._handle_message`` used to log recorded warnings while still inside the +``warnings.catch_warnings(record=True)`` block. Because ``record=True`` forces +an "always" filter, a warning emitted by a logging handler during that logging +step was appended to the very list being iterated, so the loop never +terminated. The loop is synchronous, so task cancellation could not interrupt +it. + +The fix snapshots the recorded warnings and logs them after leaving the +``catch_warnings`` block, so handler-emitted warnings can no longer extend the +iteration. This test drives ``_handle_message`` with a request that records one +warning and a logging handler that itself warns on every record; the handler +must be invoked exactly once. The handler stops re-warning after a cap so that +the pre-fix infinite loop terminates and fails the assertion instead of hanging +the test session. +""" + +import logging +import warnings +from unittest.mock import AsyncMock, Mock + +import pytest + +import mcp.types as types +from mcp.server.lowlevel.server import Server +from mcp.server.session import ServerSession +from mcp.shared.session import RequestResponder + + +class _WarningEmittingHandler(logging.Handler): + """A logging handler whose emit() raises a warning, mimicking e.g. a + timestamp formatter that calls a deprecated API on every record. It stops + after ``cap`` records so a regressed (looping) build still terminates.""" + + def __init__(self, cap: int = 100) -> None: + super().__init__() + self.emit_count = 0 + self._cap = cap + + def emit(self, record: logging.LogRecord) -> None: + self.emit_count += 1 + if self.emit_count <= self._cap: + warnings.warn("warning raised while logging", stacklevel=1) + + +@pytest.mark.anyio +async def test_handle_message_logs_each_warning_once_when_handler_warns(): + server = Server("test-server") + + session = Mock(spec=ServerSession) + session.send_log_message = AsyncMock() + + async def _handle_request_that_warns(*args: object, **kwargs: object) -> None: + warnings.warn("warning raised while handling the request", stacklevel=1) + + server._handle_request = _handle_request_that_warns # type: ignore[assignment] + + responder = Mock(spec=RequestResponder) + responder.request = types.ClientRequest(root=types.PingRequest(method="ping")) + responder.__enter__ = Mock(return_value=responder) + responder.__exit__ = Mock(return_value=None) + + server_logger = logging.getLogger("mcp.server.lowlevel.server") + handler = _WarningEmittingHandler() + server_logger.addHandler(handler) + previous_level = server_logger.level + server_logger.setLevel(logging.INFO) + + try: + with warnings.catch_warnings(): + warnings.simplefilter("always") + await server._handle_message(responder, session, {}, raise_exceptions=False) + finally: + server_logger.removeHandler(handler) + server_logger.setLevel(previous_level) + + assert handler.emit_count == 1 From d1b5751e7d2cee4b79c9f458cb43fb8eb4e57dbf Mon Sep 17 00:00:00 2001 From: rahul188 Date: Sat, 18 Jul 2026 14:51:38 +0530 Subject: [PATCH 2/2] test: exercise both handler branches so coverage stays at 100% Record two warnings during handling and warn on only the first log record, so the handler's cap branch is taken in the passing run too (the repo enforces fail-under=100). Still asserts the handler is invoked once per recorded warning (twice), which a regressed build breaks by re-appending its own warning. --- tests/issues/test_3122_warning_loop.py | 31 ++++++++++++++++---------- 1 file changed, 19 insertions(+), 12 deletions(-) diff --git a/tests/issues/test_3122_warning_loop.py b/tests/issues/test_3122_warning_loop.py index 6c1624b71..5c8a9a111 100644 --- a/tests/issues/test_3122_warning_loop.py +++ b/tests/issues/test_3122_warning_loop.py @@ -9,11 +9,15 @@ The fix snapshots the recorded warnings and logs them after leaving the ``catch_warnings`` block, so handler-emitted warnings can no longer extend the -iteration. This test drives ``_handle_message`` with a request that records one -warning and a logging handler that itself warns on every record; the handler -must be invoked exactly once. The handler stops re-warning after a cap so that -the pre-fix infinite loop terminates and fails the assertion instead of hanging -the test session. +iteration. + +The test records two warnings during handling and attaches a logging handler +that itself warns on the first record only. After the fix each recorded warning +is logged exactly once, so the handler is invoked twice (once per recorded +warning) and no extra records appear. Before the fix, the handler's warning fed +back into the iterated list and the handler was invoked a third time. Warning +on only the first record keeps the handler from feeding the loop unboundedly, so +a regressed build terminates and fails the assertion instead of hanging. """ import logging @@ -29,11 +33,10 @@ class _WarningEmittingHandler(logging.Handler): - """A logging handler whose emit() raises a warning, mimicking e.g. a - timestamp formatter that calls a deprecated API on every record. It stops - after ``cap`` records so a regressed (looping) build still terminates.""" + """A logging handler whose emit() raises a warning for the first ``cap`` + records, mimicking e.g. a timestamp formatter that warns per record.""" - def __init__(self, cap: int = 100) -> None: + def __init__(self, cap: int = 1) -> None: super().__init__() self.emit_count = 0 self._cap = cap @@ -45,14 +48,15 @@ def emit(self, record: logging.LogRecord) -> None: @pytest.mark.anyio -async def test_handle_message_logs_each_warning_once_when_handler_warns(): +async def test_handle_message_logs_each_recorded_warning_once() -> None: server = Server("test-server") session = Mock(spec=ServerSession) session.send_log_message = AsyncMock() async def _handle_request_that_warns(*args: object, **kwargs: object) -> None: - warnings.warn("warning raised while handling the request", stacklevel=1) + warnings.warn("first warning raised while handling the request", stacklevel=1) + warnings.warn("second warning raised while handling the request", stacklevel=1) server._handle_request = _handle_request_that_warns # type: ignore[assignment] @@ -75,4 +79,7 @@ async def _handle_request_that_warns(*args: object, **kwargs: object) -> None: server_logger.removeHandler(handler) server_logger.setLevel(previous_level) - assert handler.emit_count == 1 + # Two warnings were recorded during handling, so the handler is invoked + # exactly twice. A regressed build re-appends the handler's own warning and + # invokes it a third time. + assert handler.emit_count == 2