From b8f17a8f1e0f64b71da83e875a8ddc1432ad7de3 Mon Sep 17 00:00:00 2001 From: NullSense Date: Sat, 22 Aug 2026 17:24:12 +0200 Subject: [PATCH] fix(mcp): make local-endpoint budgets configurable --- .../server/mcp_server/_answer_pipeline.py | 19 ++- .../repowise/server/mcp_server/_helpers.py | 36 +++++ .../server/mcp_server/tool_answer/config.py | 36 ++++- .../mcp_server/tool_answer/synthesis.py | 6 +- .../mcp/test_answer_synthesis_timeout.py | 47 +++++++ tests/unit/server/mcp/test_embed_timeout.py | 132 ++++++++++++++++++ .../mcp/test_retrieval_leg_visibility.py | 5 +- 7 files changed, 269 insertions(+), 12 deletions(-) create mode 100644 tests/unit/server/mcp/test_embed_timeout.py diff --git a/packages/server/src/repowise/server/mcp_server/_answer_pipeline.py b/packages/server/src/repowise/server/mcp_server/_answer_pipeline.py index 0bdf3bb82..6919a441c 100644 --- a/packages/server/src/repowise/server/mcp_server/_answer_pipeline.py +++ b/packages/server/src/repowise/server/mcp_server/_answer_pipeline.py @@ -64,7 +64,9 @@ node_to_file, ) from repowise.server.mcp_server._helpers import ( + _EMBED_TIMEOUT_ENV, _VECTOR_TIMEOUT_ENV, + embed_timeout_s, vector_search_timeout_s, ) from repowise.server.mcp_server._prose_symbols import symbol_backed_pages @@ -132,10 +134,11 @@ # rank-3/4 hit (~3.0-3.5). _GRAPH_EXPAND_DAMPING = 0.7 -# Budget for embedding the question. The searches that used to embed inline were -# bounded at 8s including the embed, so the round-trip keeps that ceiling now -# that it happens on its own. -_EMBED_TIMEOUT_S = 8.0 +# Budget for embedding the question is resolved live by embed_timeout_s() +# (see _helpers.py) — REPOWISE_EMBED_TIMEOUT_S, falling back to the 8s a warm +# hosted endpoint needs. The searches that used to embed inline were bounded +# at that same 8s including the embed, so the round-trip keeps that ceiling +# now that it happens on its own. # Which retrieval legs actually ran for the current question (finding A18). # @@ -262,8 +265,9 @@ async def question_vector(ctx: Any, question: str) -> list[float] | None: _QUESTION_VECTORS.move_to_end(key) return cached[1] + timeout_s = embed_timeout_s() try: - vectors = await asyncio.wait_for(store.embed_texts([question]), timeout=_EMBED_TIMEOUT_S) + vectors = await asyncio.wait_for(store.embed_texts([question]), timeout=timeout_s) except TimeoutError: # The A18 case, and the one worth naming separately: the embedder is # configured, reachable and healthy, and simply did not answer inside @@ -272,8 +276,9 @@ async def question_vector(ctx: Any, question: str) -> list[float] | None: _record_leg("embed", "timeout") _log.warning( "get_answer could not embed the question within %.1fs; retrieval " - "continues without a question vector", - _EMBED_TIMEOUT_S, + "continues without a question vector. Raise it with %s=.", + timeout_s, + _EMBED_TIMEOUT_ENV, ) return None except Exception: diff --git a/packages/server/src/repowise/server/mcp_server/_helpers.py b/packages/server/src/repowise/server/mcp_server/_helpers.py index 953c27bbb..484c4de55 100644 --- a/packages/server/src/repowise/server/mcp_server/_helpers.py +++ b/packages/server/src/repowise/server/mcp_server/_helpers.py @@ -65,6 +65,42 @@ def vector_search_timeout_s() -> float: return _VECTOR_TIMEOUT_DEFAULT_S return min(seconds, _VECTOR_TIMEOUT_MAX_S) + +# Budget for embedding a get_answer question before question_vector() gives up +# and falls back to a lexical-only answer. 8s suits a warm hosted endpoint; a +# locally served model that has just been swapped in pays a cold load first +# and blows it — the run still succeeds (question_vector logs a warning and +# returns None), so nothing an operator isn't already tailing structlog for +# marks the semantic leg as lost. Raise it with REPOWISE_EMBED_TIMEOUT_S to +# buy a cold local model the time a warm hosted one never needed. +_EMBED_TIMEOUT_ENV = "REPOWISE_EMBED_TIMEOUT_S" +_EMBED_TIMEOUT_DEFAULT_S = 8.0 +# Same client-side constraint as _VECTOR_TIMEOUT_MAX_S above: past this the +# MCP client's own tool-call timeout fires first, so a larger value here +# cannot produce results anyone still accepts. +_EMBED_TIMEOUT_MAX_S = 120.0 + + +def embed_timeout_s() -> float: + """Seconds one question-embedding call may take, from env or the default. + + An unparseable or non-positive value warns and keeps the default instead of + silently disabling the leg, matching :func:`vector_search_timeout_s` and + REPOWISE_EMBEDDING_TIMEOUT. + """ + raw = (os.environ.get(_EMBED_TIMEOUT_ENV) or "").strip() + if not raw: + return _EMBED_TIMEOUT_DEFAULT_S + try: + seconds = float(raw) + except ValueError: + seconds = float("nan") + if not seconds > 0: + _log.warning("Ignoring unusable %s=%r", _EMBED_TIMEOUT_ENV, raw) + return _EMBED_TIMEOUT_DEFAULT_S + return min(seconds, _EMBED_TIMEOUT_MAX_S) + + # Words that mark a string as a natural-language question rather than a path. # Keep this small — false positives here send genuine paths to the NL branch, # which is harmless (path lookup also runs as a fallback) but slower. diff --git a/packages/server/src/repowise/server/mcp_server/tool_answer/config.py b/packages/server/src/repowise/server/mcp_server/tool_answer/config.py index 9c0a40ce1..75d9df1d6 100644 --- a/packages/server/src/repowise/server/mcp_server/tool_answer/config.py +++ b/packages/server/src/repowise/server/mcp_server/tool_answer/config.py @@ -8,10 +8,13 @@ from __future__ import annotations +import logging import os from repowise.server.mcp_server._query_terms import STOPWORDS +_log = logging.getLogger("repowise.mcp.answer") + # How many top retrieval hits to enrich with WikiSymbol context. Enriching # every hit produces large responses that bloat the cached prompt prefix on # multi-turn agent sessions without changing the answer — the agent typically @@ -499,7 +502,38 @@ # Synthesis sampling. Answers target 150-400 words (~550 tokens), so the cap is # headroom rather than the binding constraint; generation speed is. Temperature # is low because the answer must track the retrieved excerpts, not embellish. -_SYNTHESIS_MAX_TOKENS = 1024 +# +# That headroom reasoning holds only for a non-reasoning model. A reasoning +# model spends the same budget on hidden thinking *before* emitting any answer +# token, so 1024 is not headroom for it — it is the entire allowance, and the +# call comes back empty with a ``length`` finish_reason (see +# ``synthesis._empty_completion_note``). REPOWISE_SYNTHESIS_MAX_TOKENS exists +# so such a model can be given room, instead of being swapped for a weaker one. +_SYNTHESIS_MAX_TOKENS_ENV = "REPOWISE_SYNTHESIS_MAX_TOKENS" +_SYNTHESIS_MAX_TOKENS_DEFAULT = 1024 + + +def _synthesis_max_tokens() -> int: + """The synthesis token budget, from env or the hosted-model default. + + An unparseable or non-positive value warns and keeps the default instead + of silently capping synthesis at 0 — matching how REPOWISE_EMBEDDING_TIMEOUT + and REPOWISE_VECTOR_SEARCH_TIMEOUT_S are resolved. + """ + raw = os.environ.get(_SYNTHESIS_MAX_TOKENS_ENV, "").strip() + if not raw: + return _SYNTHESIS_MAX_TOKENS_DEFAULT + try: + value = int(raw) + except ValueError: + value = 0 + if value <= 0: + _log.warning("Ignoring unusable %s=%r", _SYNTHESIS_MAX_TOKENS_ENV, raw) + return _SYNTHESIS_MAX_TOKENS_DEFAULT + return value + + +_SYNTHESIS_MAX_TOKENS = _synthesis_max_tokens() _SYNTHESIS_TEMPERATURE = 0.2 _SYSTEM_PROMPT = ( diff --git a/packages/server/src/repowise/server/mcp_server/tool_answer/synthesis.py b/packages/server/src/repowise/server/mcp_server/tool_answer/synthesis.py index 588d0db2f..ef80bf8ec 100644 --- a/packages/server/src/repowise/server/mcp_server/tool_answer/synthesis.py +++ b/packages/server/src/repowise/server/mcp_server/tool_answer/synthesis.py @@ -17,6 +17,7 @@ from repowise.server.mcp_server.tool_answer.config import ( _SYNTHESIS_MAX_TOKENS, + _SYNTHESIS_MAX_TOKENS_ENV, _SYNTHESIS_TEMPERATURE, ) @@ -300,8 +301,9 @@ def _empty_completion_note(provider, response) -> str: return ( f"DEGRADED: the model used its entire {_SYNTHESIS_MAX_TOKENS}-token " f"budget without emitting an answer ({who}). Reasoning models spend " - "that budget on hidden thinking; try a non-reasoning model for " - "synthesis. Read the listed files to answer meanwhile." + "that budget on hidden thinking before any answer token; raise it " + f"with {_SYNTHESIS_MAX_TOKENS_ENV}=, or use a non-reasoning " + "model for synthesis. Read the listed files to answer meanwhile." ) return ( f"DEGRADED: the model returned an empty completion ({who}). " diff --git a/tests/unit/server/mcp/test_answer_synthesis_timeout.py b/tests/unit/server/mcp/test_answer_synthesis_timeout.py index a4ba326d0..79c8e598b 100644 --- a/tests/unit/server/mcp/test_answer_synthesis_timeout.py +++ b/tests/unit/server/mcp/test_answer_synthesis_timeout.py @@ -19,7 +19,10 @@ from repowise.server.mcp_server.tool_answer.answer import _degraded_payload from repowise.server.mcp_server.tool_answer.config import ( _SYNTHESIS_MAX_TOKENS, + _SYNTHESIS_MAX_TOKENS_DEFAULT, + _SYNTHESIS_MAX_TOKENS_ENV, _SYNTHESIS_TEMPERATURE, + _synthesis_max_tokens, ) from repowise.server.mcp_server.tool_answer.synthesis import ( _FALLBACK_TIMEOUT_S, @@ -30,6 +33,50 @@ synthesize, ) +# --- synthesis token budget ------------------------------------------------- +# +# REPOWISE_SYNTHESIS_MAX_TOKENS: the hardcoded 1024 was headroom for a +# non-reasoning model (answers target ~550 tokens) but is the WHOLE allowance +# for one that spends the same budget on hidden thinking before any answer +# token — measured against nanbeige returning nothing at 1024, a correct +# cited answer at 8192. See _empty_completion_note below for the failure +# this override exists to escape. + + +@pytest.fixture(autouse=True) +def _no_max_tokens_override(monkeypatch): + monkeypatch.delenv(_SYNTHESIS_MAX_TOKENS_ENV, raising=False) + + +def test_default_max_tokens_matches_the_documented_default(): + assert _synthesis_max_tokens() == _SYNTHESIS_MAX_TOKENS_DEFAULT == 1024 + assert _SYNTHESIS_MAX_TOKENS == _SYNTHESIS_MAX_TOKENS_DEFAULT # process-start default + + +@pytest.mark.parametrize("raw,expected", [("8192", 8192), ("2048", 2048), (" 4096 ", 4096)]) +def test_max_tokens_env_override_is_honoured(monkeypatch, raw, expected): + monkeypatch.setenv(_SYNTHESIS_MAX_TOKENS_ENV, raw) + assert _synthesis_max_tokens() == expected + + +@pytest.mark.parametrize("bad", ["abc", "0", "-5", "3.5", ""]) +def test_unusable_max_tokens_override_keeps_the_default(monkeypatch, bad): + """An unparseable value must not zero out synthesis, matching the sibling + embed/vector-search timeout overrides.""" + monkeypatch.setenv(_SYNTHESIS_MAX_TOKENS_ENV, bad) + assert _synthesis_max_tokens() == _SYNTHESIS_MAX_TOKENS_DEFAULT + + +def test_the_degraded_message_advertises_the_override(): + """The advice a reasoning-model user actually needs, not just "try a + different model" — see synthesis._empty_completion_note.""" + note = synthesis_module._empty_completion_note( + _Provider(budget=180.0, name="ollama", model="nanbeige"), + SimpleNamespace(stop_reason="max_tokens"), + ) + assert _SYNTHESIS_MAX_TOKENS_ENV in note + assert str(_SYNTHESIS_MAX_TOKENS) in note + class _Provider: """Stand-in for a resolved provider; only the read attributes matter.""" diff --git a/tests/unit/server/mcp/test_embed_timeout.py b/tests/unit/server/mcp/test_embed_timeout.py new file mode 100644 index 000000000..1bffb4832 --- /dev/null +++ b/tests/unit/server/mcp/test_embed_timeout.py @@ -0,0 +1,132 @@ +"""The question-embed budget must be raisable, and say so when it isn't enough. + +``_EMBED_TIMEOUT_S`` used to be a hardcoded 8.0 in ``_answer_pipeline.py``. +That suits a warm hosted embedding endpoint. A locally served model that has +just been swapped in pays a cold load first — measured elsewhere in this repo +at several seconds for the analogous vector-store cold path (#1678) — and 8s +is not enough headroom. The call then raises ``TimeoutError``, +``question_vector`` returns ``None``, and ``get_answer`` still succeeds: the +run exits 0 with a lexical-only answer and nothing marking the semantic leg +as lost, unless someone is tailing ``repowise.mcp.answer`` at WARNING. + +Mirrors ``test_vector_search_timeout.py`` for the sibling budget +(``vector_search_timeout_s``), which this file's ``embed_timeout_s`` copies +the shape of on purpose: same env-override / cap / malformed-value contract. +""" + +from __future__ import annotations + +import asyncio +import logging +from types import SimpleNamespace + +import pytest + +from repowise.core.persistence.vector_store import InMemoryVectorStore +from repowise.core.providers.embedding.base import MockEmbedder +from repowise.server.mcp_server import _answer_pipeline as pipeline +from repowise.server.mcp_server._helpers import ( + _EMBED_TIMEOUT_DEFAULT_S, + _EMBED_TIMEOUT_ENV, + _EMBED_TIMEOUT_MAX_S, + embed_timeout_s, +) + +_QUESTION = "why does the retrieval pipeline embed the question up front?" + + +@pytest.fixture(autouse=True) +def _clean_env(monkeypatch): + monkeypatch.delenv(_EMBED_TIMEOUT_ENV, raising=False) + + +@pytest.fixture(autouse=True) +def _clear_vector_cache(): + """Cross-test isolation: the cache is module-level, as the store it keys on + is process-lived.""" + cache = pipeline._QUESTION_VECTORS + cache.clear() + yield + cache.clear() + + +# --------------------------------------------------------------------------- +# embed_timeout_s() — resolution contract, mirrors vector_search_timeout_s() +# --------------------------------------------------------------------------- + + +def test_default_budget_matches_the_documented_default() -> None: + assert embed_timeout_s() == _EMBED_TIMEOUT_DEFAULT_S == 8.0 + + +@pytest.mark.parametrize("raw,expected", [("60", 60.0), ("2.5", 2.5), (" 45 ", 45.0)]) +def test_env_override_is_honoured(monkeypatch, raw, expected) -> None: + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, raw) + assert embed_timeout_s() == expected + + +def test_override_is_capped(monkeypatch) -> None: + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, "9999") + assert embed_timeout_s() == _EMBED_TIMEOUT_MAX_S + + +@pytest.mark.parametrize("raw", ["abc", "0", "-5", "nan", ""]) +def test_unusable_override_keeps_the_default(monkeypatch, raw) -> None: + """An unparseable value must not disable the leg, matching REPOWISE_EMBEDDING_TIMEOUT.""" + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, raw) + assert embed_timeout_s() == _EMBED_TIMEOUT_DEFAULT_S + + +def test_no_hardcoded_eight_second_embed_budget() -> None: + """Pins the fix: the embed budget is resolved live, not baked in at import.""" + from pathlib import Path + + text = Path(pipeline.__file__).read_text(encoding="utf-8") + assert "_EMBED_TIMEOUT_S = 8.0" not in text + assert "_EMBED_TIMEOUT_S =" not in text # no hardcoded module-level constant at all + + +# --------------------------------------------------------------------------- +# question_vector() — the actual call site +# --------------------------------------------------------------------------- + + +class _SlowEmbedTextsStore(InMemoryVectorStore): + """A store whose embed_texts() takes longer than the old hardcoded budget.""" + + def __init__(self, delay: float) -> None: + super().__init__(embedder=MockEmbedder()) + self._delay = delay + + async def embed_texts(self, texts): + await asyncio.sleep(self._delay) + return await super().embed_texts(texts) + + +async def test_question_vector_gives_up_at_the_default_budget(monkeypatch, caplog) -> None: + """The exact silent-degradation case this override exists for: a slow + local embed used to blow the hardcoded 8s. Proven here at a tight budget + so the test doesn't itself take 8s.""" + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, "0.01") + store = _SlowEmbedTextsStore(delay=1.0) + ctx = SimpleNamespace(vector_store=store) + + with caplog.at_level(logging.WARNING, logger="repowise.mcp.answer"): + result = await pipeline.question_vector(ctx, _QUESTION) + + assert result is None + assert any("embed the question" in r.getMessage() for r in caplog.records) + assert any(_EMBED_TIMEOUT_ENV in r.getMessage() for r in caplog.records), caplog.text + + +async def test_question_vector_survives_a_cold_embed_once_raised(monkeypatch) -> None: + """The fix in one assertion: the same slow embed that timed out above + succeeds once the operator raises the budget past it.""" + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, "2") + store = _SlowEmbedTextsStore(delay=0.05) + ctx = SimpleNamespace(vector_store=store) + + result = await pipeline.question_vector(ctx, _QUESTION) + + assert result is not None + assert len(result) == store._embedder.dimensions diff --git a/tests/unit/server/mcp/test_retrieval_leg_visibility.py b/tests/unit/server/mcp/test_retrieval_leg_visibility.py index 68bdc4667..7ae5be295 100644 --- a/tests/unit/server/mcp/test_retrieval_leg_visibility.py +++ b/tests/unit/server/mcp/test_retrieval_leg_visibility.py @@ -20,6 +20,7 @@ import pytest from repowise.server.mcp_server import _answer_pipeline as pipeline +from repowise.server.mcp_server._helpers import _EMBED_TIMEOUT_ENV class _Store: @@ -70,7 +71,7 @@ def fresh_record(): @pytest.mark.asyncio async def test_a_healthy_leg_records_ok(monkeypatch): - monkeypatch.setattr(pipeline, "_EMBED_TIMEOUT_S", 0.5) + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, "0.5") await pipeline._safe_vector_search(_Ctx(store=_Store()), "how does retrieval work") assert pipeline.retrieval_legs()["vector"] == "ok" assert pipeline.degraded_legs(pipeline.retrieval_legs()) == [] @@ -79,7 +80,7 @@ async def test_a_healthy_leg_records_ok(monkeypatch): @pytest.mark.asyncio async def test_an_embed_timeout_is_named_and_does_not_fail_the_call(monkeypatch): """The exact A18 shape: the answer still comes back, lexical-only.""" - monkeypatch.setattr(pipeline, "_EMBED_TIMEOUT_S", 0.05) + monkeypatch.setenv(_EMBED_TIMEOUT_ENV, "0.05") ctx = _Ctx(store=_Store(embed_hangs=True)) results = await pipeline._safe_vector_search(ctx, "how does retrieval work")