fix: diagnose silent filter-install failures, dedup filters, address CI findings

- embedded_server.py's ImportError guard around the log-filter install was
  too broad: it silently swallowed ANY import failure, not just "older
  ha-mcp missing the module" (the intended case). Since third-party
  dependencies (fastmcp, pydantic) are deliberately NOT reinstalled per
  config entry (_purge_ha_mcp_modules only purges ha_mcp.* modules), a
  version mismatch there could break the import invisibly -- no crash, no
  log, the filters just silently never install. Narrow the tolerated case to
  ModuleNotFoundError for exactly "ha_mcp.log_filters", and log a WARNING for
  anything else (including a failure from install_sdk_log_filters() itself),
  so this class of failure is never invisible again.

- install_sdk_log_filters() had no dedup guard: the in-process embedded
  server calls it on every _serve() reload without a process restart, so
  filters accumulated one more redundant instance per reload (CodeRabbit).
  Add _add_filter_once() and a regression test that calls the installer
  twice and asserts exactly one filter of each type.

- Narrow a test helper's `except BaseException` to `except Exception`
  (CodeQL py/catch-base-exception): the child coroutines it runs only ever
  raise Exception subclasses.

- Add docstrings to functions/methods touched by this change that lacked
  one (log_filters.py's three filter() methods, new/modified test methods
  and fixtures in test_session_disconnect_log_filter.py and
  test_embedded_server.py).

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

Author: swissmo

custom_components/ha_mcp_tools/embedded_server.py

@@ -251,13 +251,40 @@ def _install_log_filters_if_available() -> None:
     site: the installed server version is user-controlled (channel choice,
     pip-spec override), so an older ha-mcp without ``ha_mcp.log_filters`` must
     keep serving -- the filters are simply absent there, as they are today.
+
+    Only a ``ModuleNotFoundError`` for exactly ``ha_mcp.log_filters`` is that
+    "older ha-mcp" case and is swallowed silently. Anything else -- a version
+    mismatch in a third-party dependency this import touches (fastmcp,
+    pydantic), which ``_purge_ha_mcp_modules`` deliberately does NOT
+    reinstall per config entry, so a stale one left over from a previous
+    install can break this import -- is logged instead of silently doing
+    nothing: log cosmetics must never block startup, but they also must
+    never fail invisibly.
     """
     try:
         from ha_mcp.log_filters import install_sdk_log_filters
-    except ImportError:
-        # Older installed ha-mcp: no filter helper to install.
+    except ModuleNotFoundError as err:
+        if err.name != "ha_mcp.log_filters":
+            _LOGGER.warning(
+                "Could not install MCP SDK log-noise filters (missing "
+                "dependency %s); continuing without them: %s",
+                err.name,
+                err,
+            )
         return
-    install_sdk_log_filters()
+    except ImportError as err:
+        _LOGGER.warning(
+            "Could not install MCP SDK log-noise filters; continuing without them: %s",
+            err,
+        )
+        return
+    try:
+        install_sdk_log_filters()
+    except Exception as err:
+        _LOGGER.warning(
+            "Could not install MCP SDK log-noise filters; continuing without them: %s",
+            err,
+        )
 
 
 class EmbeddedServerManager:

src/ha_mcp/log_filters.py

@@ -40,6 +40,7 @@ class StatelessSessionLogFilter(logging.Filter):
     """
 
     def filter(self, record: logging.LogRecord) -> bool:
+        """Drop the routine stateless-teardown record; pass everything else."""
         if record.name != "mcp.server.streamable_http":
             return True
         try:
@@ -63,6 +64,7 @@ class ToolValidationLogFilter(logging.Filter):
     """
 
     def filter(self, record: logging.LogRecord) -> bool:
+        """Demote a known-benign validation/tool-error record to WARNING."""
         if record.name != "fastmcp.server.server" or not record.exc_info:
             return True
 
@@ -128,6 +130,7 @@ class SessionDisconnectLogFilter(logging.Filter):
     """
 
     def filter(self, record: logging.LogRecord) -> bool:
+        """Demote a disconnect-caused 'session crashed' record to WARNING."""
         if record.name != "mcp.server.streamable_http_manager" or not record.exc_info:
             return True
 
@@ -146,19 +149,30 @@ def filter(self, record: logging.LogRecord) -> bool:
         return True
 
 
+def _add_filter_once(logger_name: str, filter_cls: type[logging.Filter]) -> None:
+    """Attach one ``filter_cls`` instance to ``logger_name``, unless already present.
+
+    ``install_sdk_log_filters()`` can run more than once per process: the
+    in-process embedded server calls it on every ``_serve()`` reload without
+    a process restart, and process-wide ``logging`` state (including each
+    named logger's filter list) persists across those reloads. Without this
+    guard, filters would accumulate one more redundant instance per reload.
+    """
+    logger = logging.getLogger(logger_name)
+    if any(isinstance(f, filter_cls) for f in logger.filters):
+        return
+    logger.addFilter(filter_cls())
+
+
 def install_sdk_log_filters() -> None:
     """Attach the demotion filters above to their target SDK/fastmcp loggers.
 
     Every HTTP launcher must call this: the CLI (``ha_mcp.__main__``), the
     Home Assistant app's ``start.py``, and the in-process embedded server
     (``ha_mcp_tools/embedded_server.py``) each build and run their own
     Streamable HTTP app, so none of them share another launcher's logging
-    setup.
+    setup. Safe to call repeatedly -- see ``_add_filter_once``.
     """
-    logging.getLogger("mcp.server.streamable_http").addFilter(
-        StatelessSessionLogFilter()
-    )
-    logging.getLogger("mcp.server.streamable_http_manager").addFilter(
-        SessionDisconnectLogFilter()
-    )
-    logging.getLogger("fastmcp.server.server").addFilter(ToolValidationLogFilter())
+    _add_filter_once("mcp.server.streamable_http", StatelessSessionLogFilter)
+    _add_filter_once("mcp.server.streamable_http_manager", SessionDisconnectLogFilter)
+    _add_filter_once("fastmcp.server.server", ToolValidationLogFilter)

tests/src/unit/test_embedded_server.py

@@ -2629,6 +2629,7 @@ class TestServeLogFilters:
 
     @pytest.fixture(autouse=True)
     def _isolate_env(self):
+        """Snapshot/restore the env vars _thread_main stages, per-test."""
         keys = ("HA_MCP_CONFIG_DIR", "HA_MCP_EMBEDDED")
         saved = {k: os.environ.get(k) for k in keys}
         for key in keys:
@@ -2641,6 +2642,7 @@ def _isolate_env(self):
                 os.environ[key] = value
 
     def test_serve_installs_log_filters(self, tmp_path, monkeypatch):
+        """_serve calls install_sdk_log_filters() when it is available."""
         mgr, _hass, _entry = _manager(
             tmp_path, options={OPT_SERVER_URL: "http://ha.local:8123"}
         )
@@ -2664,9 +2666,10 @@ def http_app(self, path, stateless_http):
         assert isinstance(mgr._thread_exc, _StopServe)
 
     def test_serve_tolerates_missing_log_filters_module(self, tmp_path, monkeypatch):
-        # Backward-compat: an OLDER bundled ha-mcp (the component reaches users
-        # ahead of the server) has no log_filters module. _serve must swallow
-        # the ImportError and keep serving, same as the browser-landing guard.
+        """Backward-compat: an OLDER bundled ha-mcp (the component reaches
+        users ahead of the server) has no log_filters module. _serve must
+        swallow the ImportError and keep serving, same as the
+        browser-landing guard."""
         mgr, _hass, _entry = _manager(
             tmp_path, options={OPT_SERVER_URL: "http://ha.local:8123"}
         )

tests/src/unit/test_log_filters_install.py

@@ -0,0 +1,46 @@
+"""Unit tests for install_sdk_log_filters()'s idempotency."""
+
+import logging
+
+from ha_mcp.log_filters import (
+    SessionDisconnectLogFilter,
+    StatelessSessionLogFilter,
+    ToolValidationLogFilter,
+    install_sdk_log_filters,
+)
+
+_TARGET_LOGGERS = {
+    "mcp.server.streamable_http": StatelessSessionLogFilter,
+    "mcp.server.streamable_http_manager": SessionDisconnectLogFilter,
+    "fastmcp.server.server": ToolValidationLogFilter,
+}
+
+
+class TestInstallSdkLogFiltersIdempotent:
+    """The in-process embedded server calls this on every reload without a
+    process restart, so process-wide logger filter lists persist across
+    calls -- a second call must not add a second instance of each filter."""
+
+    def setup_method(self):
+        """Snapshot each target logger's current filter list."""
+        self._saved = {
+            name: logging.getLogger(name).filters[:] for name in _TARGET_LOGGERS
+        }
+
+    def teardown_method(self):
+        """Restore each target logger's filter list, undoing this test's calls."""
+        for name, filters in self._saved.items():
+            logging.getLogger(name).filters[:] = filters
+
+    def test_second_call_does_not_duplicate_filters(self):
+        """Calling the installer twice must not attach a filter twice."""
+        install_sdk_log_filters()
+        install_sdk_log_filters()
+
+        for name, filter_cls in _TARGET_LOGGERS.items():
+            matches = [
+                f for f in logging.getLogger(name).filters if isinstance(f, filter_cls)
+            ]
+            assert len(matches) == 1, (
+                f"{name} must carry exactly one {filter_cls.__name__}, got {len(matches)}"
+            )

tests/src/unit/test_session_disconnect_log_filter.py

@@ -12,14 +12,16 @@
 
 
 async def _raise_closed_resource_error() -> None:
+    """Raise the exact exception the disconnect race produces."""
     raise anyio.ClosedResourceError()
 
 
 async def _raise_runtime_error() -> None:
+    """Raise an unrelated failure, standing in for a real server bug."""
     raise RuntimeError("real bug")
 
 
-async def _run_in_task_group(*coro_funcs) -> BaseException:
+async def _run_in_task_group(*coro_funcs) -> Exception:
     """Run each of ``coro_funcs`` as a task-group child and return the raised
     exception -- reproducing the actual shape mcp.server.lowlevel.server.Server.run()
     produces: it dispatches each incoming message via
@@ -28,12 +30,17 @@ async def _run_in_task_group(*coro_funcs) -> BaseException:
     child. anyio always wraps that in an ExceptionGroup, even for a single
     failure -- a hand-built ``exc_info`` with a bare exception does not
     reproduce that boundary.
+
+    Narrowed to ``Exception`` (not ``BaseException``): the child coroutines
+    here only ever raise ``Exception`` subclasses, so anyio's task group
+    wraps them in ``ExceptionGroup`` (an ``Exception``), never
+    ``BaseExceptionGroup``-only content like a cancellation.
     """
     try:
         async with anyio.create_task_group() as tg:
             for coro_func in coro_funcs:
                 tg.start_soon(coro_func)
-    except BaseException as exc:
+    except Exception as exc:
         return exc
     raise AssertionError("task group did not raise")
 
@@ -42,6 +49,7 @@ class TestSessionDisconnectLogFilter:
     """Verify the filter demotes disconnect-caused 'session crashed' tracebacks."""
 
     def setup_method(self):
+        """Create a fresh filter instance for each test."""
         self.log_filter = SessionDisconnectLogFilter()
 
     def _make_record(
@@ -50,6 +58,7 @@ def _make_record(
         msg: str,
         exc: BaseException | None,
     ) -> logging.LogRecord:
+        """Build a bare LogRecord carrying ``exc`` as its exc_info, if given."""
         exc_info = (type(exc), exc, None) if exc is not None else None
         return logging.LogRecord(
             name=name,
@@ -62,8 +71,8 @@ def _make_record(
         )
 
     def test_demotes_stateless_session_crash_from_closed_resource_error(self):
-        # Exactly what mcp/server/streamable_http_manager.py's
-        # _handle_stateless_request logs when the client already disconnected.
+        """Exactly what mcp/server/streamable_http_manager.py's
+        _handle_stateless_request logs when the client already disconnected."""
         err = anyio.ClosedResourceError()
         record = self._make_record(
             "mcp.server.streamable_http_manager",
@@ -79,8 +88,8 @@ def test_demotes_stateless_session_crash_from_closed_resource_error(self):
         assert "Stateless session crashed" in record.getMessage()
 
     def test_demotes_stateful_session_crash_from_closed_resource_error(self):
-        # The stateful runner's equivalent log line -- same race, same fix,
-        # even though every HTTP entry point currently forces stateless_http.
+        """The stateful runner's equivalent log line -- same race, same fix,
+        even though every HTTP entry point currently forces stateless_http."""
         err = anyio.ClosedResourceError()
         record = self._make_record(
             "mcp.server.streamable_http_manager",
@@ -92,10 +101,10 @@ def test_demotes_stateful_session_crash_from_closed_resource_error(self):
         assert record.exc_info is None
 
     async def test_demotes_real_task_group_exception_group(self):
-        # The shape actually logged in production: mcp.server.lowlevel.server
-        # dispatches message handling via anyio.create_task_group().start_soon,
-        # so a ClosedResourceError from _send_response arrives here wrapped in
-        # an ExceptionGroup, not as a bare exception.
+        """The shape actually logged in production: mcp.server.lowlevel.server
+        dispatches message handling via anyio.create_task_group().start_soon,
+        so a ClosedResourceError from _send_response arrives here wrapped in
+        an ExceptionGroup, not as a bare exception."""
         caught = await _run_in_task_group(_raise_closed_resource_error)
         assert isinstance(caught, BaseExceptionGroup)
 
@@ -110,9 +119,9 @@ async def test_demotes_real_task_group_exception_group(self):
         assert "client disconnected before response delivery" in record.getMessage()
 
     async def test_leaves_mixed_exception_group_at_error(self):
-        # A task group with one ClosedResourceError AND one unrelated failure
-        # signals a real problem alongside the expected disconnect race -- the
-        # whole record must stay at ERROR with its traceback intact.
+        """A task group with one ClosedResourceError AND one unrelated failure
+        signals a real problem alongside the expected disconnect race -- the
+        whole record must stay at ERROR with its traceback intact."""
         caught = await _run_in_task_group(
             _raise_closed_resource_error, _raise_runtime_error
         )
@@ -129,8 +138,8 @@ async def test_leaves_mixed_exception_group_at_error(self):
         assert record.exc_info is original_exc_info
 
     def test_passes_bare_exception_through_untouched(self):
-        # An actual server bug on this logger must keep its traceback and
-        # ERROR level -- only the known-benign disconnect race is demoted.
+        """An actual server bug on this logger must keep its traceback and
+        ERROR level -- only the known-benign disconnect race is demoted."""
         err = RuntimeError("server bug")
         record = self._make_record(
             "mcp.server.streamable_http_manager",
@@ -143,6 +152,7 @@ def test_passes_bare_exception_through_untouched(self):
         assert record.exc_info is original_exc_info
 
     def test_leaves_other_loggers_unchanged(self):
+        """Only the SDK's session-manager logger is ever touched."""
         err = anyio.ClosedResourceError()
         record = self._make_record(
             "some.other.logger",
@@ -154,6 +164,7 @@ def test_leaves_other_loggers_unchanged(self):
         assert record.exc_info is not None
 
     def test_passes_record_without_exc_info(self):
+        """A record with no attached exception is never touched."""
         record = self._make_record(
             "mcp.server.streamable_http_manager",
             "Stateless session crashed",
@@ -167,33 +178,42 @@ class TestIsOnlyClosedResourceErrors:
     """Direct coverage of the recursive classifier the filter relies on."""
 
     def test_bare_closed_resource_error(self):
+        """A bare ClosedResourceError matches on its own."""
         assert _is_only_closed_resource_errors(anyio.ClosedResourceError()) is True
 
     def test_bare_other_exception(self):
+        """An unrelated bare exception never matches."""
         assert _is_only_closed_resource_errors(RuntimeError("x")) is False
 
     def test_group_of_one_closed_resource_error(self):
+        """A single-item group wrapping just the known-benign exception matches."""
         group = ExceptionGroup("eg", [anyio.ClosedResourceError()])
         assert _is_only_closed_resource_errors(group) is True
 
     def test_nested_group_of_closed_resource_errors(self):
+        """Nested groups are unwrapped recursively, matching all-benign leaves."""
         inner = ExceptionGroup("inner", [anyio.ClosedResourceError()])
         outer = ExceptionGroup("outer", [inner, anyio.ClosedResourceError()])
         assert _is_only_closed_resource_errors(outer) is True
 
     def test_mixed_group_is_rejected(self):
+        """A group with even one non-benign leaf must not match."""
         group = ExceptionGroup("eg", [anyio.ClosedResourceError(), RuntimeError("x")])
         assert _is_only_closed_resource_errors(group) is False
 
     def test_empty_group_is_rejected(self):
-        # Defensive: an ExceptionGroup always carries at least one exception
-        # in practice, but `all([])` is vacuously True -- guard against ever
-        # demoting on a group with nothing in it.
+        """Defensive: an ExceptionGroup always carries at least one exception
+        in practice, but `all([])` is vacuously True -- guard against ever
+        demoting on a group with nothing in it. ExceptionGroup itself refuses
+        to construct empty, so this pins that guarantee rather than exercising
+        the classifier's own guard directly."""
         with pytest.raises(ValueError):
             ExceptionGroup("empty", [])
 
 
 class TestSessionDisconnectLogFilterWiring:
+    """End-to-end: _setup_logging wires the filter onto real logger output."""
+
     def test_setup_logging_wires_filter_and_demotes_output(self, monkeypatch):
         """Integration: ``_setup_logging`` attaches the filter to the SDK's
         session-manager logger, so a real ``ClosedResourceError``-caused