From 39a07dc48e9d4f6a0b751b6982795d39a6f437ff Mon Sep 17 00:00:00 2001
From: Tony Narlock <tony@git-pull.com>
Date: Sun, 7 Jun 2026 14:21:45 -0500
Subject: [PATCH] mcp(fix[middleware]): Stop error logging from masking the
 tool result
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

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.
---
 src/libtmux_mcp/middleware.py | 11 ++++++-
 tests/test_middleware.py      | 62 +++++++++++++++++++++++++++++++++++
 2 files changed, 72 insertions(+), 1 deletion(-)

diff --git a/src/libtmux_mcp/middleware.py b/src/libtmux_mcp/middleware.py
index dfc751e..13a393b 100644
--- a/src/libtmux_mcp/middleware.py
+++ b/src/libtmux_mcp/middleware.py
@@ -27,6 +27,7 @@
 
 from __future__ import annotations
 
+import contextlib
 import hashlib
 import logging
 import time
@@ -339,7 +340,15 @@ async def on_call_tool(
         try:
             return await call_next(context)
         except Exception as error:
-            self._log_error(error, context)
+            # Invariant: error logging must never mask the tool result. A
+            # broken logging handler (e.g. a stale rich.traceback import
+            # after the venv was rebuilt under a long-lived server) would
+            # otherwise raise out of ``_log_error`` and replace the real
+            # failure with a misleading ``Internal error``. Suppress
+            # silently — logging the failure here would re-enter the same
+            # broken handler. See #66.
+            with contextlib.suppress(Exception):
+                self._log_error(error, context)
             return _error_tool_result(error, context)
 
 
diff --git a/tests/test_middleware.py b/tests/test_middleware.py
index 9384c38..b2a12f4 100644
--- a/tests/test_middleware.py
+++ b/tests/test_middleware.py
@@ -869,6 +869,68 @@ async def _call() -> None:
     assert levels == [expected_level]
 
 
+class LogMaskingCase(t.NamedTuple):
+    """One ``on_call_tool`` scenario for the logging-masks-result guard."""
+
+    test_id: str
+    logger_raises: bool
+
+
+LOG_MASKING_CASES: tuple[LogMaskingCase, ...] = (
+    LogMaskingCase(test_id="logging-ok", logger_raises=False),
+    LogMaskingCase(test_id="logging-raises", logger_raises=True),
+)
+
+
+@pytest.mark.parametrize(
+    "case",
+    LOG_MASKING_CASES,
+    ids=[case.test_id for case in LOG_MASKING_CASES],
+)
+def test_error_logging_never_masks_tool_result(
+    case: LogMaskingCase,
+    monkeypatch: pytest.MonkeyPatch,
+) -> None:
+    """A failing logging handler must not replace the real tool error.
+
+    Regression guard for #66: when the active logging handler raised
+    while formatting the error record (e.g. a stale ``rich.traceback``
+    import after the venv was rebuilt under a long-lived server),
+    ``_log_error`` escaped ``on_call_tool``'s ``except`` and the stock
+    transform surfaced a misleading ``Internal error`` in place of the
+    real failure. The call site now suppresses logging exceptions so
+    the original error always reaches ``_error_tool_result``.
+    """
+    from libtmux_mcp.middleware import ToolErrorResultMiddleware
+
+    middleware = ToolErrorResultMiddleware(transform_errors=True)
+    if case.logger_raises:
+
+        def _boom(*_args: t.Any, **_kwargs: t.Any) -> None:
+            msg = "No module named 'rich.traceback'"
+            raise ModuleNotFoundError(msg)
+
+        monkeypatch.setattr(middleware.logger, "log", _boom)
+
+    async def _call_next(_context: t.Any) -> str:
+        msg = "real tool failure"
+        raise RuntimeError(msg)
+
+    ctx: MiddlewareContext[CallToolRequestParams] = MiddlewareContext(
+        message=CallToolRequestParams(name="boom_tool", arguments={}),
+    )
+
+    result = asyncio.run(middleware.on_call_tool(ctx, _call_next))
+
+    assert result.is_error is True
+    text = result.content[0].text
+    assert "real tool failure" in text
+    assert "rich.traceback" not in text
+    # ``_log_error`` bumps the counter before it reaches the log call,
+    # so the counter advances whether or not logging then fails.
+    assert sum(middleware.error_counts.values()) == 1
+
+
 def test_schema_validation_failure_marked_expected_in_meta() -> None:
     """Argument-schema failures report ``expected=True`` in result meta.