"""TDD — musehub#208: SQLAlchemy echo=True floods MCP stdio's stdout with raw SQL. Root cause: ``musehub/db/database.py::init_db()`` creates the async engine with ``echo=settings.debug``. SQLAlchemy's own ``InstanceLogger.__init__`` (``sqlalchemy/log.py``) installs a hardcoded ``logging.StreamHandler(sys.stdout)`` on the engine's logger whenever ``echo`` is truthy and that logger has no handlers yet — this has nothing to do with ``stdio_server.py``'s own ``logging.basicConfig(stream=sys.stderr)`` call, which only configures the *root* logger, not the uniquely-named per-engine child logger SQLAlchemy creates. Under this project's default local-dev config (``DEBUG=true``), every SQL statement gets written directly to stdout — the exact byte stream the stdio MCP transport uses as its JSON-RPC wire protocol. Fix: ``init_db()`` gains an ``echo`` override parameter; the stdio transport passes ``echo=False`` unconditionally, regardless of ``settings.debug`` — stdio's wire protocol correctness can never depend on a debug flag someone else sets for an unrelated (HTTP) transport. """ from __future__ import annotations from unittest.mock import AsyncMock, MagicMock, patch import pytest @pytest.mark.asyncio class TestInitDbEchoOverride: async def test_default_uses_settings_debug_true(self) -> None: from musehub.db import database as db_module with ( patch.object(db_module.settings, "debug", True), patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"), patch.object(db_module.settings, "slow_query_threshold_ms", 0), patch( "musehub.db.database.create_async_engine", return_value=MagicMock(sync_engine=MagicMock()), ) as mock_create, patch("musehub.db.database.async_sessionmaker"), patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock), ): await db_module.init_db() assert mock_create.call_args.kwargs["echo"] is True async def test_default_uses_settings_debug_false(self) -> None: from musehub.db import database as db_module with ( patch.object(db_module.settings, "debug", False), patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"), patch.object(db_module.settings, "slow_query_threshold_ms", 0), patch( "musehub.db.database.create_async_engine", return_value=MagicMock(sync_engine=MagicMock()), ) as mock_create, patch("musehub.db.database.async_sessionmaker"), patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock), ): await db_module.init_db() assert mock_create.call_args.kwargs["echo"] is False async def test_echo_override_forces_false_even_when_debug_true(self) -> None: """The actual regression guard: an explicit echo=False override must win over settings.debug=True.""" from musehub.db import database as db_module with ( patch.object(db_module.settings, "debug", True), patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"), patch.object(db_module.settings, "slow_query_threshold_ms", 0), patch( "musehub.db.database.create_async_engine", return_value=MagicMock(sync_engine=MagicMock()), ) as mock_create, patch("musehub.db.database.async_sessionmaker"), patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock), ): await db_module.init_db(echo=False) assert mock_create.call_args.kwargs["echo"] is False async def test_echo_override_forces_true_even_when_debug_false(self) -> None: from musehub.db import database as db_module with ( patch.object(db_module.settings, "debug", False), patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"), patch.object(db_module.settings, "slow_query_threshold_ms", 0), patch( "musehub.db.database.create_async_engine", return_value=MagicMock(sync_engine=MagicMock()), ) as mock_create, patch("musehub.db.database.async_sessionmaker"), patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock), ): await db_module.init_db(echo=True) assert mock_create.call_args.kwargs["echo"] is True @pytest.mark.asyncio class TestStdioServerForcesEchoOff: async def test_stdio_run_calls_init_db_with_echo_false(self) -> None: """musehub#208's actual fix target: the stdio transport's own startup must never let settings.debug leak SQL onto stdout.""" from musehub.mcp import stdio_server import asyncio mock_init_db = AsyncMock() loop = asyncio.get_event_loop() real_stream_reader = asyncio.StreamReader async def _fake_connect_read_pipe(protocol_factory, pipe): protocol = protocol_factory() protocol.connection_made(MagicMock()) return MagicMock(), protocol async def _fake_connect_write_pipe(protocol_factory, pipe): return MagicMock(), protocol_factory() def _capture_reader(*a, **kw): r = real_stream_reader() r.feed_eof() return r with ( patch.object(loop, "connect_read_pipe", side_effect=_fake_connect_read_pipe), patch.object(loop, "connect_write_pipe", side_effect=_fake_connect_write_pipe), patch("musehub.db.init_db", mock_init_db), patch("asyncio.StreamReader", side_effect=_capture_reader), ): await stdio_server._run() mock_init_db.assert_awaited_once_with(echo=False)