mcp(fix[middleware]): Stop error logging from masking the tool result#67
Open
tony wants to merge 1 commit into
Open
mcp(fix[middleware]): Stop error logging from masking the tool result#67tony wants to merge 1 commit into
tony wants to merge 1 commit into
Conversation
why: When the active logging handler raised while formatting an error record — e.g. a stale rich.traceback import after the venv was rebuilt under a long-lived stdio server — _log_error escaped on_call_tool's except block, so _error_tool_result never ran. The stock fastmcp transform then surfaced a misleading "Internal error: No module named 'rich.traceback'" in place of the real tool failure, hiding both the cause and the remedy. The error_callback invocation right below was already guarded; the logger.log call on the same path was not. what: - Wrap the _log_error call in on_call_tool with contextlib.suppress so a failing logging handler can never replace the original error; _error_tool_result is always reached. Suppress silently — logging the failure would re-enter the same broken handler. - Add a parametrized regression test (logging-ok / logging-raises) asserting the original error text survives and the rich.traceback message never leaks into the result.
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #67 +/- ##
==========================================
+ Coverage 84.51% 84.59% +0.07%
==========================================
Files 42 42
Lines 2758 2759 +1
Branches 370 370
==========================================
+ Hits 2331 2334 +3
+ Misses 322 321 -1
+ Partials 105 104 -1 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
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
A failure in the error-logging path could replace the real tool error.
ToolErrorResultMiddleware.on_call_toollogged the error before converting it, and_log_error'sself.logger.log(..., exc_info=...)call was unguarded — so when the active handler raised while formatting the record, the logging exception escaped theexceptblock and_error_tool_resultnever ran. The stock fastmcp transform then surfaced a misleadingInternal error: …in place of the real failure.The concrete trigger we hit: a long-lived stdio server whose virtualenv was rebuilt underneath it. fastmcp's
RichHandlerlazily importsrich.tracebackthe first time it renders anexc_inforecord; after the rebuild that import raisedModuleNotFoundError, and every tool call surfacedInternal error: No module named 'rich.traceback'— masking both the cause and the remedy (reconnect the server). The defect is independent of that trigger: any handler failure could mask a real tool error.The asymmetry that pinpointed it: the
error_callbackinvocation immediately below in_log_erroris already wrapped intry/except; thelogger.logcall on the same path was not.Changes
src/libtmux_mcp/middleware.py: wrap the_log_errorcall inon_call_toolwithcontextlib.suppress(Exception), guaranteeing_error_tool_resultalways runs. The suppress is silent by design — logging the failure would re-enter the same broken handler.tests/test_middleware.py: parametrized regression test (logging-ok/logging-raises) drivingon_call_toolwith acall_nextthat raises a known error and a logger patched to raise; asserts the original error text survives and therich.tracebackmessage never leaks into the result.A follow-up worth considering separately (not in this PR): fail fast at startup — eagerly import the traceback dependency or run a one-shot self-check so a broken environment surfaces loudly at launch rather than on the first tool call.
Fixes #66.
Test plan
main(drop thesuppress,logging-raisesreproduces theModuleNotFoundErrorescape) and passes with the fix.uv run ruff format ./uv run ruff check . --fix --show-fixes— clean.uv run mypy— no issues.uv run pytest— full suite green.