|
| 1 | +"""Unit tests for SessionDisconnectLogFilter.""" |
| 2 | + |
| 3 | +import logging |
| 4 | + |
| 5 | +import anyio |
| 6 | + |
| 7 | +from ha_mcp.__main__ import SessionDisconnectLogFilter |
| 8 | + |
| 9 | + |
| 10 | +class TestSessionDisconnectLogFilter: |
| 11 | + """Verify the filter demotes disconnect-caused 'session crashed' tracebacks.""" |
| 12 | + |
| 13 | + def setup_method(self): |
| 14 | + self.log_filter = SessionDisconnectLogFilter() |
| 15 | + |
| 16 | + def _make_record( |
| 17 | + self, |
| 18 | + name: str, |
| 19 | + msg: str, |
| 20 | + exc: BaseException | None, |
| 21 | + ) -> logging.LogRecord: |
| 22 | + exc_info = (type(exc), exc, None) if exc is not None else None |
| 23 | + return logging.LogRecord( |
| 24 | + name=name, |
| 25 | + level=logging.ERROR, |
| 26 | + pathname="", |
| 27 | + lineno=0, |
| 28 | + msg=msg, |
| 29 | + args=(), |
| 30 | + exc_info=exc_info, |
| 31 | + ) |
| 32 | + |
| 33 | + def test_demotes_stateless_session_crash_from_closed_resource_error(self): |
| 34 | + # Exactly what mcp/server/streamable_http_manager.py's |
| 35 | + # _handle_stateless_request logs when the client already disconnected. |
| 36 | + err = anyio.ClosedResourceError() |
| 37 | + record = self._make_record( |
| 38 | + "mcp.server.streamable_http_manager", |
| 39 | + "Stateless session crashed", |
| 40 | + err, |
| 41 | + ) |
| 42 | + assert self.log_filter.filter(record) is True |
| 43 | + assert record.levelno == logging.WARNING |
| 44 | + assert record.levelname == "WARNING" |
| 45 | + assert record.exc_info is None |
| 46 | + assert record.exc_text is None |
| 47 | + assert "client disconnected before response delivery" in record.getMessage() |
| 48 | + assert "Stateless session crashed" in record.getMessage() |
| 49 | + |
| 50 | + def test_demotes_stateful_session_crash_from_closed_resource_error(self): |
| 51 | + # The stateful runner's equivalent log line -- same race, same fix, |
| 52 | + # even though every HTTP entry point currently forces stateless_http. |
| 53 | + err = anyio.ClosedResourceError() |
| 54 | + record = self._make_record( |
| 55 | + "mcp.server.streamable_http_manager", |
| 56 | + "Session abc123 crashed", |
| 57 | + err, |
| 58 | + ) |
| 59 | + assert self.log_filter.filter(record) is True |
| 60 | + assert record.levelno == logging.WARNING |
| 61 | + assert record.exc_info is None |
| 62 | + |
| 63 | + def test_passes_bare_exception_through_untouched(self): |
| 64 | + # An actual server bug on this logger must keep its traceback and |
| 65 | + # ERROR level -- only the known-benign disconnect race is demoted. |
| 66 | + err = RuntimeError("server bug") |
| 67 | + record = self._make_record( |
| 68 | + "mcp.server.streamable_http_manager", |
| 69 | + "Stateless session crashed", |
| 70 | + err, |
| 71 | + ) |
| 72 | + original_exc_info = record.exc_info |
| 73 | + assert self.log_filter.filter(record) is True |
| 74 | + assert record.levelno == logging.ERROR |
| 75 | + assert record.exc_info is original_exc_info |
| 76 | + |
| 77 | + def test_leaves_other_loggers_unchanged(self): |
| 78 | + err = anyio.ClosedResourceError() |
| 79 | + record = self._make_record( |
| 80 | + "some.other.logger", |
| 81 | + "Stateless session crashed", |
| 82 | + err, |
| 83 | + ) |
| 84 | + assert self.log_filter.filter(record) is True |
| 85 | + assert record.levelno == logging.ERROR |
| 86 | + assert record.exc_info is not None |
| 87 | + |
| 88 | + def test_passes_record_without_exc_info(self): |
| 89 | + record = self._make_record( |
| 90 | + "mcp.server.streamable_http_manager", |
| 91 | + "Stateless session crashed", |
| 92 | + None, |
| 93 | + ) |
| 94 | + assert self.log_filter.filter(record) is True |
| 95 | + assert record.levelno == logging.ERROR |
| 96 | + |
| 97 | + def test_setup_logging_wires_filter_and_demotes_output(self, monkeypatch): |
| 98 | + """Integration: ``_setup_logging`` attaches the filter to the SDK's |
| 99 | + session-manager logger, so a real ``ClosedResourceError``-caused |
| 100 | + 'Stateless session crashed' entry loses its traceback and ERROR level |
| 101 | + in actual output, while an unrelated exception on the same logger |
| 102 | + still comes through as a full ERROR traceback. |
| 103 | +
|
| 104 | + ``logging.basicConfig`` is stubbed to a no-op for the same reason as |
| 105 | + the sibling ``StatelessSessionLogFilter`` wiring test: its real |
| 106 | + ``basicConfig(force=True)`` would tear down and *close* the root |
| 107 | + logger's handlers, including pytest's capture handlers. |
| 108 | + """ |
| 109 | + import io |
| 110 | + |
| 111 | + from ha_mcp import __main__ as ha_main |
| 112 | + |
| 113 | + sdk_logger = logging.getLogger("mcp.server.streamable_http_manager") |
| 114 | + # _setup_logging also attaches filters to sibling loggers; save/restore |
| 115 | + # them too or they leak into other tests. |
| 116 | + stateless_logger = logging.getLogger("mcp.server.streamable_http") |
| 117 | + fastmcp_logger = logging.getLogger("fastmcp.server.server") |
| 118 | + saved_sdk_filters = sdk_logger.filters[:] |
| 119 | + saved_stateless_filters = stateless_logger.filters[:] |
| 120 | + saved_fastmcp_filters = fastmcp_logger.filters[:] |
| 121 | + saved_propagate = sdk_logger.propagate |
| 122 | + saved_level = sdk_logger.level |
| 123 | + monkeypatch.setattr(ha_main.logging, "basicConfig", lambda *a, **k: None) |
| 124 | + try: |
| 125 | + ha_main._setup_logging("INFO", force=True) |
| 126 | + assert any( |
| 127 | + isinstance(f, SessionDisconnectLogFilter) for f in sdk_logger.filters |
| 128 | + ), "_setup_logging must attach SessionDisconnectLogFilter to the SDK's session-manager logger" |
| 129 | + |
| 130 | + disconnect_buf = io.StringIO() |
| 131 | + handler = logging.StreamHandler(disconnect_buf) |
| 132 | + handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s")) |
| 133 | + sdk_logger.addHandler(handler) |
| 134 | + sdk_logger.setLevel(logging.INFO) |
| 135 | + sdk_logger.propagate = False |
| 136 | + try: |
| 137 | + try: |
| 138 | + raise anyio.ClosedResourceError() |
| 139 | + except anyio.ClosedResourceError: |
| 140 | + sdk_logger.exception("Stateless session crashed") |
| 141 | + finally: |
| 142 | + sdk_logger.removeHandler(handler) |
| 143 | + |
| 144 | + disconnect_out = disconnect_buf.getvalue() |
| 145 | + assert "client disconnected before response delivery" in disconnect_out |
| 146 | + assert "WARNING" in disconnect_out |
| 147 | + assert "Traceback" not in disconnect_out, ( |
| 148 | + "the ClosedResourceError-caused crash must lose its traceback" |
| 149 | + ) |
| 150 | + |
| 151 | + bug_buf = io.StringIO() |
| 152 | + handler = logging.StreamHandler(bug_buf) |
| 153 | + handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s")) |
| 154 | + sdk_logger.addHandler(handler) |
| 155 | + try: |
| 156 | + try: |
| 157 | + raise RuntimeError("real bug") |
| 158 | + except RuntimeError: |
| 159 | + sdk_logger.exception("Stateless session crashed") |
| 160 | + finally: |
| 161 | + sdk_logger.removeHandler(handler) |
| 162 | + |
| 163 | + bug_out = bug_buf.getvalue() |
| 164 | + assert "real bug" in bug_out |
| 165 | + assert "Traceback" in bug_out, ( |
| 166 | + "an unrelated exception on this logger must keep its traceback" |
| 167 | + ) |
| 168 | + finally: |
| 169 | + sdk_logger.filters[:] = saved_sdk_filters |
| 170 | + stateless_logger.filters[:] = saved_stateless_filters |
| 171 | + fastmcp_logger.filters[:] = saved_fastmcp_filters |
| 172 | + sdk_logger.propagate = saved_propagate |
| 173 | + sdk_logger.setLevel(saved_level) |
0 commit comments