diff --git a/tests/tools/test_mcp_startup_summary_names_failures.py b/tests/tools/test_mcp_startup_summary_names_failures.py new file mode 100644 index 0000000000..5b37669adb --- /dev/null +++ b/tests/tools/test_mcp_startup_summary_names_failures.py @@ -0,0 +1,68 @@ +"""The MCP startup summary names every failing server with its reason (#114746). + +``MCP: registered N tool(s) from M server(s) (2 failed)`` left the failing identity diagnosable +only by elimination from the per-server ``registered`` lines, and a candidate skipped for its +retry cooldown never got a per-server WARNING at all. +""" + +import logging +from types import SimpleNamespace + +import pytest + +from tools.mcp_tool_scope import _server_key + + +@pytest.fixture +def _clean_registry(): + from tools import mcp_tool + + yield + with mcp_tool._lock: + for name in ("ghost", "cooled", "ok"): + mcp_tool._servers.pop(_server_key(name), None) + mcp_tool._server_connect_errors.pop(_server_key(name), None) + mcp_tool._server_connect_retry_after.pop(_server_key(name), None) + mcp_tool._server_connecting.discard(_server_key(name)) + + +def _summaries(caplog): + return [r.getMessage() for r in caplog.records if "tool(s) from" in r.getMessage()] + + +@pytest.mark.no_isolate +def test_register_summary_names_failed_server_with_reason(monkeypatch, tmp_path, caplog, _clean_registry): + """Production path: ``register_mcp_servers`` with a stdio command that cannot start. The + summary line itself carries the server name and the recorded connect error.""" + monkeypatch.setenv("HERMES_HOME", str(tmp_path)) + from tools import mcp_tool + from tools.mcp_tool_discovery import register_mcp_servers + + monkeypatch.setattr(mcp_tool, "_MAX_INITIAL_CONNECT_RETRIES", 1) + monkeypatch.setattr(mcp_tool, "_MAX_BACKOFF_SECONDS", 0.1) + missing = str(tmp_path / "no-such-mcp-binary") + + with caplog.at_level(logging.INFO, logger="tools.mcp_tool"): + register_mcp_servers({"ghost": {"command": missing, "connect_timeout": 15}}) + + summaries = _summaries(caplog) + assert len(summaries) == 1, summaries + assert summaries[0].startswith("MCP: registered 0 tool(s) from 0 server(s) (1 failed: ghost (") + assert "no-such-mcp-binary" in summaries[0] + + +def test_summary_marks_candidate_skipped_for_cooldown(caplog, _clean_registry): + """A candidate this pass never attempted (still inside its retry cooldown) has no fresh + connect error: it is named with an explicit "not attempted" reason instead of vanishing + into the count; a healthy server keeps the summary unchanged.""" + from tools import mcp_tool + from tools.mcp_tool_discovery import _log_summary + + with mcp_tool._lock: + mcp_tool._servers[_server_key("ok")] = SimpleNamespace(_registered_tool_names=["t1", "t2"]) + with caplog.at_level(logging.INFO, logger="tools.mcp_tool"): + _log_summary(" MCP:", ["ok", "cooled"]) + + assert _summaries(caplog) == [ + " MCP: 2 tool(s) from 1 server(s) (1 failed: cooled (not attempted (in retry cooldown)))" + ] diff --git a/tools/mcp_tool_discovery.py b/tools/mcp_tool_discovery.py index 628a67a162..22d7ba0f54 100644 --- a/tools/mcp_tool_discovery.py +++ b/tools/mcp_tool_discovery.py @@ -417,24 +417,32 @@ def _run_discovery_pass(new_servers: Dict[str, dict]) -> None: _set_interrupt(True) -def _connected_summary(names, *, lazy_tools: int = 0, lazy_servers: int = 0) -> Tuple[int, int, int]: - """(tool count, connected count, failed count) for candidate names, plus lazy servers.""" +def _connected_summary(names, *, lazy_tools: int = 0, + lazy_servers: int = 0) -> Tuple[int, int, List[Tuple[str, str]]]: + """(tool count, connected count, ``[(failed name, reason)]``) for candidate names, plus lazy + servers. The reason is the recorded connect error; a candidate this pass never attempted (still + inside its retry cooldown from an earlier failure) has none.""" with _core._lock: keys = {n: _server_key(n) for n in names} connected = [n for n in names if keys[n] in _core._servers and keys[n] not in _core._server_connect_errors] tool_count = sum(len(getattr(_core._servers[keys[n]], "_registered_tool_names", [])) for n in connected) - failed = len(names) - len(connected) + failed = [(n, _core._server_connect_errors.get(keys[n]) or "not attempted (in retry cooldown)") + for n in names if n not in connected] return tool_count + lazy_tools, len(connected) + lazy_servers, failed def _log_summary(prefix: str, names, **lazy) -> None: - """Log `` N tool(s) from M server(s) (K failed)`` when anything happened.""" + """Log `` N tool(s) from M server(s) (K failed: name (reason), ...)`` when anything + happened. The failures are named on the summary line itself (#114746): the count alone left + the failing server identifiable only by elimination, and a candidate skipped for its retry + cooldown never gets a per-server WARNING at all.""" new_tool_count, connected_count, failed = _connected_summary(names, **lazy) if new_tool_count or failed or lazy.get("lazy_servers"): summary = f"{prefix} {new_tool_count} tool(s) from {connected_count} server(s)" if failed: - summary += f" ({failed} failed)" + summary += f" ({len(failed)} failed: " + "; ".join( + f"{name} ({reason})" for name, reason in failed) + ")" if lazy.get("lazy_servers"): summary += f" ({lazy['lazy_servers']} lazy, not spawned yet)" logger.info(summary) diff --git a/website/docs/user-guide/features/mcp.md b/website/docs/user-guide/features/mcp.md index 09258517fd..1b84bd943a 100644 --- a/website/docs/user-guide/features/mcp.md +++ b/website/docs/user-guide/features/mcp.md @@ -834,6 +834,16 @@ npx --version Then verify your config and restart Hermes. +The startup summary in `agent.log` names every server that did not register, with the recorded +connect error, so you never have to work out the failing one by elimination: + +``` +MCP: registered 116 tool(s) from 4 server(s) (2 failed: github (Connection closed); notion (HTTP 401 from POST https://mcp.notion.com/mcp)) +``` + +A server that was skipped this pass because it is still inside its retry cooldown from an earlier +failure is listed as `not attempted (in retry cooldown)`. + ### Remote (HTTP) server rejects the connection `hermes mcp test ` reports what the server actually answered. When the MCP SDK can only say