hermes-agent/tests/tools/test_mcp_server_log_notifications.py
Teknium 39975613b1
test: prune wave 2 + speed fixes — 28,106 → 19,757 test functions, suite wall 315s → 294s
Second, deeper pass over tools/gateway/hermes_cli plus first pass over
the trees wave 1 missed (acp, acp_adapter, skills, computer_use, docker,
dashboard, conformance, monitoring, secret_sources, hermes_state,
providers). Same rubric as wave 1 (AGENTS.md test policy); security,
alternation/caching invariants, issue-number regressions, and E2E kept.

Real test-quality fixes found and rooted out along the way:
- tests/tools/test_command_guards.py made real auxiliary-LLM HTTPS calls
  (DEFAULT_CONFIG smart-approval leaked in) — pinned approval
  mode=manual via autouse fixture: 17.4s → 0.4s.
- test_model_switch_custom_providers.py / test_user_providers_model_switch.py
  silently probed live provider catalogs (~2s/test) — stubbed
  cached_provider_model_ids/provider_model_ids/fetch_api_models.
- test_telegram_noise_filter.py: 15-platform copy-paste matrix over
  shared gateway.run logic → 3 representative platforms (55s → 3.9s).
- test_gateway_shutdown.py: stop()'s 5s interrupt-deadline loop spun on
  MagicMock agents — interrupt.side_effect now clears _running_agents
  (22s → 1.0s).
- test_gateway_inactivity_timeout.py poll-harness timings shrunk 3-5x
  (24s → 1.1s); test_mcp_stability.py backoff/SIGTERM-grace sleeps
  patched (15.4s → 2.5s); test_async_delegation.py negative-drain wait
  5s → 0.5s.
- test_telegram_init_deadline.py: loop-block margin restored to 1.0s
  with rationale comment — the watchdog-dump assertion needs the loop
  blocked well past deadline+grace under parallel load (flaked once in
  the 40-worker verification run at a 0.2s margin).

Verification: full hermetic suite via scripts/run_tests.sh —
2,438 files, 21,718 tests passed, 0 failed, 293.9s wall.
Suite totals vs original baseline: 46,820 → 19,757 test functions
(−57.8%), wall 583.5s → 293.9s (−50%), subprocess CPU 13,564s → 11,623s.
2026-07-29 13:39:40 -07:00

83 lines
3.1 KiB
Python

"""Tests for MCP server log notification handling (port of anomalyco/opencode#34529).
MCP servers can emit ``notifications/message`` logging notifications
(RFC 5424 syslog levels). The MCP SDK's default ``logging_callback``
silently discards them; Hermes now passes ``_make_logging_callback()``
to ``ClientSession`` so server-side diagnostics land in agent.log,
tagged with the server name.
"""
import logging
from types import SimpleNamespace
import pytest
from tools.mcp_tool import (
_MCP_LOG_LEVEL_MAP,
_MCP_LOGGING_CALLBACK_SUPPORTED,
MCPServerTask,
)
def _params(level="info", data="hello", logger_name=None):
return SimpleNamespace(level=level, data=data, logger=logger_name)
class TestLogLevelMap:
def test_all_mcp_levels_mapped(self):
# MCP spec (RFC 5424) defines these eight levels.
for lvl in ("debug", "info", "notice", "warning",
"error", "critical", "alert", "emergency"):
assert lvl in _MCP_LOG_LEVEL_MAP
def test_severity_ordering(self):
assert _MCP_LOG_LEVEL_MAP["debug"] == logging.DEBUG
assert _MCP_LOG_LEVEL_MAP["notice"] == logging.INFO
assert _MCP_LOG_LEVEL_MAP["warning"] == logging.WARNING
assert _MCP_LOG_LEVEL_MAP["emergency"] == logging.ERROR
class TestLoggingCallback:
@pytest.mark.asyncio
async def test_routes_to_hermes_logger_with_server_tag(self, caplog):
server = MCPServerTask("log_srv")
callback = server._make_logging_callback()
with caplog.at_level(logging.INFO, logger="tools.mcp_tool"):
await callback(_params(level="info", data="server started"))
assert any(
"MCP server log [log_srv]: server started" in rec.getMessage()
for rec in caplog.records
)
@pytest.mark.asyncio
async def test_includes_sub_logger_name(self, caplog):
server = MCPServerTask("log_srv")
callback = server._make_logging_callback()
with caplog.at_level(logging.WARNING, logger="tools.mcp_tool"):
await callback(_params(level="warning", data="rate limited",
logger_name="http"))
assert any(
"MCP server log [log_srv/http]: rate limited" in rec.getMessage()
and rec.levelno == logging.WARNING
for rec in caplog.records
)
@pytest.mark.asyncio
async def test_handler_never_raises(self):
server = MCPServerTask("log_srv")
callback = server._make_logging_callback()
# A params object missing every attribute must not blow up the
# SDK's notification dispatch loop.
await callback(object())
class TestSDKSupportGate:
def test_current_sdk_supports_logging_callback(self):
# The pinned MCP SDK in this repo supports logging_callback; if this
# starts failing after an SDK downgrade the feature silently degrades
# (by design), but we want to know.
import inspect
from mcp import ClientSession
expected = "logging_callback" in inspect.signature(ClientSession).parameters
assert _MCP_LOGGING_CALLBACK_SUPPORTED == expected