fix: prevent infinite warning-logging loop in _handle_message#3124
Open
rahul188 wants to merge 2 commits into
Open
fix: prevent infinite warning-logging loop in _handle_message#3124rahul188 wants to merge 2 commits into
rahul188 wants to merge 2 commits into
Conversation
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: modelcontextprotocol#3122 Reported-by: fas89
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.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Fixes #3122
Server._handle_message(mcp/server/lowlevel/server.py) logs the warnings recorded during message handling while still inside thewarnings.catch_warnings(record=True)block. Becauserecord=Trueinstalls an "always" filter, any warning emitted by a logging handler while thoselogger.infocalls run is appended to the very list being iterated, so thefor warning in wloop never terminates. The loop is synchronous with no await points, so task cancellation cannot interrupt it; the handling task wedges until an external timeout kills the process. This shows up in practice when a formatter on the logger chain warns per record (for example adatetime.utcnow()-based JSON timestamp formatter on Python 3.12+), and it is easy to trigger under pytest, which runs with an "always" warning filter.Fix
Snapshot the recorded warnings and emit the log lines after leaving the
catch_warningsblock. Once the block exits, the recordingshowwarningis restored, so a warning raised by a logging handler goes to the normal warnings machinery instead of being appended to the snapshot, and the loop iterates a fixed list. Behaviour for the normal case (recorded warnings are still logged once each) is unchanged.Tests
Added
tests/issues/test_3122_warning_loop.py. It drives_handle_messagewith a request that records one warning and attaches a logging handler that itself warns on every record, then asserts the handler is invoked exactly once. The handler stops re-warning after a cap so that a regressed (looping) build terminates and fails the assertion rather than hanging the session. The test fails onv1.xbefore this change (handler invoked many times) and passes after.This targets
v1.x;mainalready dropped this block in the v2 receive-path rewrite, so it is not affected.