Skip to content

mcp(fix[middleware]): Stop error logging from masking the tool result#67

Open
tony wants to merge 1 commit into
mainfrom
fix-error-logging-masks-result
Open

mcp(fix[middleware]): Stop error logging from masking the tool result#67
tony wants to merge 1 commit into
mainfrom
fix-error-logging-masks-result

Conversation

@tony
Copy link
Copy Markdown
Member

@tony tony commented Jun 7, 2026

Summary

A failure in the error-logging path could replace the real tool error. ToolErrorResultMiddleware.on_call_tool logged the error before converting it, and _log_error's self.logger.log(..., exc_info=...) call was unguarded — so when the active handler raised while formatting the record, the logging exception escaped the except block and _error_tool_result never ran. The stock fastmcp transform then surfaced a misleading Internal 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 RichHandler lazily imports rich.traceback the first time it renders an exc_info record; after the rebuild that import raised ModuleNotFoundError, and every tool call surfaced Internal 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_callback invocation immediately below in _log_error is already wrapped in try/except; the logger.log call on the same path was not.

Changes

  • src/libtmux_mcp/middleware.py: wrap the _log_error call in on_call_tool with contextlib.suppress(Exception), guaranteeing _error_tool_result always 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) driving on_call_tool with a call_next that raises a known error and a logger patched to raise; asserts the original error text survives and the rich.traceback message 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

  • New test fails on main (drop the suppress, logging-raises reproduces the ModuleNotFoundError escape) 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.

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-commenter
Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 84.59%. Comparing base (9bdccd1) to head (39a07dc).

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.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Error middleware masks the real tool error when the logging path itself fails

2 participants