fix(mcp): startup summary names every failed server with its connect error
`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. The per-server WARNING fires only on the immediate-failure path; a candidate skipped for its retry cooldown (a failure from an earlier pass) is counted as failed with no line of its own at all. `_connected_summary` now returns `(name, reason)` pairs and `_log_summary` prints them inline: `(2 failed: github (Connection closed); notion (HTTP 401 ...))`. The reason is the recorded `_server_connect_errors` entry (already credential-scrubbed by `_format_connect_error`); a candidate never attempted this pass reads `not attempted (in retry cooldown)`. One line, no second WARNING per server on the path that already warns. Slimmer redo of #114794 (@liuhao1024, earliest) and #114872 (@Finn763): both name the failures via an extra WARNING per server; inline on the summary keeps the immediate-failure path at its current two WARNINGs and still covers the cooldown case. #114872's extra `_sanitize_error` pass is redundant with the recorder. Fixes #114746 Co-authored-by: liuhao1024 <sunsky.lau@gmail.com> Co-authored-by: finn763 <165816600+finn763@users.noreply.github.com>
This commit is contained in:
68
tests/tools/test_mcp_startup_summary_names_failures.py
Normal file
68
tests/tools/test_mcp_startup_summary_names_failures.py
Normal file
@@ -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)))"
|
||||
]
|
||||
@@ -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 ``<prefix> N tool(s) from M server(s) (K failed)`` when anything happened."""
|
||||
"""Log ``<prefix> 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)
|
||||
|
||||
@@ -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 <name>` reports what the server actually answered. When the MCP SDK can only say
|
||||
|
||||
Reference in New Issue
Block a user