gabriel/musehub — blame/sha256:7/test_stdio_sql_echo.py

1 files

1 commits

0 hotspots

0 🧊 dead

0 💥 blast risk

sha256:1 fix: getting-started page's muse --version sample output showed musehub… · gabriel · Oct 23, 2026

1	"""TDD — musehub#208: SQLAlchemy echo=True floods MCP stdio's stdout with raw SQL.
2
3	Root cause: ``musehub/db/database.py::init_db()`` creates the async engine
4	with ``echo=settings.debug``. SQLAlchemy's own ``InstanceLogger.__init__``
5	(``sqlalchemy/log.py``) installs a hardcoded ``logging.StreamHandler(sys.stdout)``
6	on the engine's logger whenever ``echo`` is truthy and that logger has no
7	handlers yet — this has nothing to do with ``stdio_server.py``'s own
8	``logging.basicConfig(stream=sys.stderr)`` call, which only configures the
9	root logger, not the uniquely-named per-engine child logger SQLAlchemy
10	creates. Under this project's default local-dev config (``DEBUG=true``),
11	every SQL statement gets written directly to stdout — the exact byte
12	stream the stdio MCP transport uses as its JSON-RPC wire protocol.
13
14	Fix: ``init_db()`` gains an ``echo`` override parameter; the stdio
15	transport passes ``echo=False`` unconditionally, regardless of
16	``settings.debug`` — stdio's wire protocol correctness can never depend
17	on a debug flag someone else sets for an unrelated (HTTP) transport.
18	"""
19	from __future__ import annotations
20
21	from unittest.mock import AsyncMock, MagicMock, patch
22
23	import pytest
24
25
26	@pytest.mark.asyncio
27	class TestInitDbEchoOverride:
28	async def test_default_uses_settings_debug_true(self) -> None:
29	from musehub.db import database as db_module
30
31	with (
32	patch.object(db_module.settings, "debug", True),
33	patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"),
34	patch.object(db_module.settings, "slow_query_threshold_ms", 0),
35	patch(
36	"musehub.db.database.create_async_engine",
37	return_value=MagicMock(sync_engine=MagicMock()),
38	) as mock_create,
39	patch("musehub.db.database.async_sessionmaker"),
40	patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock),
41	):
42	await db_module.init_db()
43	assert mock_create.call_args.kwargs["echo"] is True
44
45	async def test_default_uses_settings_debug_false(self) -> None:
46	from musehub.db import database as db_module
47
48	with (
49	patch.object(db_module.settings, "debug", False),
50	patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"),
51	patch.object(db_module.settings, "slow_query_threshold_ms", 0),
52	patch(
53	"musehub.db.database.create_async_engine",
54	return_value=MagicMock(sync_engine=MagicMock()),
55	) as mock_create,
56	patch("musehub.db.database.async_sessionmaker"),
57	patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock),
58	):
59	await db_module.init_db()
60	assert mock_create.call_args.kwargs["echo"] is False
61
62	async def test_echo_override_forces_false_even_when_debug_true(self) -> None:
63	"""The actual regression guard: an explicit echo=False override must
64	win over settings.debug=True."""
65	from musehub.db import database as db_module
66
67	with (
68	patch.object(db_module.settings, "debug", True),
69	patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"),
70	patch.object(db_module.settings, "slow_query_threshold_ms", 0),
71	patch(
72	"musehub.db.database.create_async_engine",
73	return_value=MagicMock(sync_engine=MagicMock()),
74	) as mock_create,
75	patch("musehub.db.database.async_sessionmaker"),
76	patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock),
77	):
78	await db_module.init_db(echo=False)
79	assert mock_create.call_args.kwargs["echo"] is False
80
81	async def test_echo_override_forces_true_even_when_debug_false(self) -> None:
82	from musehub.db import database as db_module
83
84	with (
85	patch.object(db_module.settings, "debug", False),
86	patch.object(db_module.settings, "database_url", "postgresql+asyncpg://u:p@h/d"),
87	patch.object(db_module.settings, "slow_query_threshold_ms", 0),
88	patch(
89	"musehub.db.database.create_async_engine",
90	return_value=MagicMock(sync_engine=MagicMock()),
91	) as mock_create,
92	patch("musehub.db.database.async_sessionmaker"),
93	patch("musehub.db.schema_check.assert_schema_matches_orm", new_callable=AsyncMock),
94	):
95	await db_module.init_db(echo=True)
96	assert mock_create.call_args.kwargs["echo"] is True
97
98
99	@pytest.mark.asyncio
100	class TestStdioServerForcesEchoOff:
101	async def test_stdio_run_calls_init_db_with_echo_false(self) -> None:
102	"""musehub#208's actual fix target: the stdio transport's own
103	startup must never let settings.debug leak SQL onto stdout."""
104	from musehub.mcp import stdio_server
105
106	import asyncio
107
108	mock_init_db = AsyncMock()
109	loop = asyncio.get_event_loop()
110	real_stream_reader = asyncio.StreamReader
111
112	async def _fake_connect_read_pipe(protocol_factory, pipe):
113	protocol = protocol_factory()
114	protocol.connection_made(MagicMock())
115	return MagicMock(), protocol
116
117	async def _fake_connect_write_pipe(protocol_factory, pipe):
118	return MagicMock(), protocol_factory()
119
120	def _capture_reader(a, *kw):
121	r = real_stream_reader()
122	r.feed_eof()
123	return r
124
125	with (
126	patch.object(loop, "connect_read_pipe", side_effect=_fake_connect_read_pipe),
127	patch.object(loop, "connect_write_pipe", side_effect=_fake_connect_write_pipe),
128	patch("musehub.db.init_db", mock_init_db),
129	patch("asyncio.StreamReader", side_effect=_capture_reader),
130	):
131	await stdio_server._run()
132
133	mock_init_db.assert_awaited_once_with(echo=False)

test_stdio_sql_echo.py file-level

`test_stdio_sql_echo.py` file-level