From dacc43906a7189ee2e4a79ff886733237e643f77 Mon Sep 17 00:00:00 2001 From: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> Date: Sat, 15 Aug 2026 03:05:51 -0700 Subject: [PATCH] fix(hooks-session-naming): fall back to priority provider on role-resolution empty, not silent skip MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When hooks-session-naming resolves a model_role and gets a clean empty result (zero candidates), the code previously returned None and skipped session naming entirely. The feature then silently never ran, making the system harder to reason about and harder to test. A deterministic config gap should fail loud, not silent. This change falls back to the session's normal priority provider when role resolution returns cleanly empty, logs a warning naming both the role that failed to resolve and the provider actually substituted, then fires naming once per session (subsequent calls drop to DEBUG). This deliberately narrows PR #300 (fix(hooks): session-naming abort on role-resolution failure, not silent downgrade) and does not undo it: - Resolver raises an exception → still aborts. Unchanged. An exception is an unknown, possibly transient failure; falling back could route onto the expensive model on every retry — the cost leak #300 guarded against. - Resolver returns cleanly empty → now falls back loudly. This is a deterministic config gap. Aborting means the feature never runs; falling back means it at least tries and admits what it did. Related: This silent skip confounded a platform A/B test. The Linux run showed zero errors not because the defect was absent, but because naming had silently skipped and never exercised the provider code path. The Windows run had a fast candidate, ran naming, and surfaced a real provider-lifecycle defect (PR #93). Out of scope: If resolved is non-empty but no entry in providers matches the resolved name, the loop falls through to the generic fallback with no warning at all — a related silent gap left for follow-up. 🤖 Generated with [Amplifier](https://github.com/microsoft/amplifier) Co-Authored-By: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> --- .../__init__.py | 84 ++++++++++++----- .../tests/test_session_naming.py | 90 ++++++++++++++++--- 2 files changed, 140 insertions(+), 34 deletions(-) diff --git a/modules/hooks-session-naming/amplifier_module_hooks_session_naming/__init__.py b/modules/hooks-session-naming/amplifier_module_hooks_session_naming/__init__.py index deb02d82..fb7a2707 100644 --- a/modules/hooks-session-naming/amplifier_module_hooks_session_naming/__init__.py +++ b/modules/hooks-session-naming/amplifier_module_hooks_session_naming/__init__.py @@ -103,6 +103,12 @@ def __init__(self, coordinator: Any, config: SessionNamingConfig): self.config = config self._defer_counts: dict[str, int] = {} self._pending_tasks: set[asyncio.Task] = set() + # Tracks which sessions have already received the "model_role + # resolved to no candidates, falling back" WARNING (see + # _call_provider). Naming retries every few turns for the life of a + # session, so without this a stable config gap would re-emit the + # identical warning on every retry. + self._role_fallback_warned: set[str] = set() async def on_orchestrator_complete( self, event: str, data: dict[str, Any] @@ -248,7 +254,7 @@ async def _generate_name( # Call the provider — hard timeout caps stalled providers try: response = await asyncio.wait_for( - self._call_provider(prompt), timeout=10.0 + self._call_provider(prompt, session_id), timeout=10.0 ) except asyncio.TimeoutError: logger.warning( @@ -454,7 +460,9 @@ def _truncate_content(self, content: str, max_len: int) -> str: truncated = truncated[:last_space] return truncated + "..." - async def _call_provider(self, prompt: str) -> str | None: + async def _call_provider( + self, prompt: str, session_id: str | None = None + ) -> str | None: """Call the LLM provider to generate name/description. Resolution order (highest to lowest priority): @@ -466,14 +474,26 @@ async def _call_provider(self, prompt: str) -> str | None: at all), logs a debug message and falls back to #2 — that fallback is legitimate and intended. - But when a model_role_resolver IS registered and the resolution itself - fails (resolves to no candidates, or raises), that is a failure of an - explicitly-configured routing preference, not an absent one. Silently - substituting the fallback provider in that case would mean a transient - resolver error (e.g. a provider API hiccup while listing models) quietly - routes a cheap background chore onto the session's primary/expensive - model. Instead, abort this naming attempt (return None) and let the - self-retrying trigger try again on a later turn. + When a model_role_resolver IS registered and resolution itself raises + (e.g. a transient provider API hiccup while listing models), the + failure mode is unknown and possibly transient. Silently substituting + the fallback provider in that case could quietly route a cheap + background chore onto the session's primary/expensive model on every + retry until the transient error clears. So this case still aborts + (returns None) and lets the self-retrying trigger try again on a + later turn. + + But when the resolver runs cleanly and simply resolves to *no + candidates* for the configured role (e.g. no "fast" model configured + for the active provider), that is a stable configuration gap, not a + transient error — retrying later changes nothing. Skipping silently + in that case means session naming is a feature that quietly never + runs, with only a log line nobody reads to explain why. So this case + falls back to #2 (the session's own default/priority provider) + instead of skipping, and logs a WARNING naming the unresolved role + and the provider substituted for it — once per session (via + ``session_id``), since naming retries every few turns and repeating + the identical warning on every retry would just be noise. """ try: providers = self.coordinator.get("providers") @@ -484,6 +504,7 @@ async def _call_provider(self, prompt: str) -> str | None: # Resolution order: model_role > priority provider provider = None model_override: str | None = None + role_had_no_candidates = False if self.config.model_role: # Look up the model_role_resolver capability registered by @@ -524,19 +545,42 @@ async def _call_provider(self, prompt: str) -> str | None: provider = p break else: + role_had_no_candidates = True + + # Fallback: use first/priority provider. Reached when model_role + # is unset, no resolver capability is registered, OR the role + # resolved to no candidates (role_had_no_candidates, handled + # below with a loud warning instead of a silent substitution). + if provider is None: + fallback_key = next(iter(providers), None) + provider = providers.get(fallback_key) if fallback_key else None + + if role_had_no_candidates and provider is not None: + warn_key = session_id or "" + if warn_key not in self._role_fallback_warned: + self._role_fallback_warned.add(warn_key) logger.warning( - "model_role %r resolved to no candidates; skipping" - " session naming for this turn rather than silently" - " falling back to the priority (expensive) provider" - " — will retry on a later turn", + "model_role %r resolved to no candidates; session" + " naming is falling back to provider %r (the" + " session's own default) instead of skipping." + " This uses whatever model that provider is" + " already configured with, which may be more" + " expensive than intended — configure a %r" + " candidate in the routing matrix to route naming" + " to a cheap model instead. (Further occurrences" + " this session are logged at DEBUG.)", + self.config.model_role, + fallback_key, self.config.model_role, ) - return None - - # Fallback: use first/priority provider (only reached when - # model_role is unset, or no resolver capability is registered) - if provider is None: - provider = next(iter(providers.values()), None) + else: + logger.debug( + "model_role %r again resolved to no candidates;" + " reusing fallback provider %r (already warned" + " once this session)", + self.config.model_role, + fallback_key, + ) if not provider: logger.warning("No provider available for session naming") diff --git a/modules/hooks-session-naming/tests/test_session_naming.py b/modules/hooks-session-naming/tests/test_session_naming.py index 0130c4eb..626cff16 100644 --- a/modules/hooks-session-naming/tests/test_session_naming.py +++ b/modules/hooks-session-naming/tests/test_session_naming.py @@ -377,14 +377,21 @@ async def test_no_model_role_uses_priority_provider(self) -> None: assert request.model is None, "No model override without model_role" @pytest.mark.asyncio - async def test_resolver_empty_result_aborts_without_calling_provider(self) -> None: - """Resolver present but resolves to [] must abort, NOT fall back to the - priority provider. + async def test_resolver_empty_result_falls_back_to_priority_provider( + self, caplog + ) -> None: + """Resolver present but resolves to [] must fall back to the session's + priority provider AND log a WARNING identifying the unresolved role + and the provider substituted for it -- naming must still run. This is the load-bearing regression test for the bug: a resolver that - legitimately exists but fails to resolve any candidates (e.g. a transient - provider error inside list_models()) must never silently substitute the - session's primary/expensive model for a background naming chore. + resolves to no candidates for a configured model_role (e.g. no "fast" + model configured for the active provider) is a *stable configuration + gap*, not a transient error -- retrying later changes nothing. Skipping + silently in that case means session naming is a feature that quietly + never runs. Naming must still happen, using the session's own default + provider, with a loud warning explaining why a role-based routing + preference was not honored. """ priority_provider = _make_mock_provider() providers = {"provider-priority": priority_provider} @@ -396,17 +403,72 @@ async def test_resolver_empty_result_aborts_without_calling_provider(self) -> No model_role="fast", ) - result = await hook._call_provider("name this session") + with caplog.at_level("WARNING"): + result = await hook._call_provider("name this session", "session-abc") - assert result is None, ( - "Must abort (return None) when model_role resolves to no candidates" + assert result is not None, ( + "Naming must still run against the fallback provider when " + "model_role resolves to no candidates, not abort" ) - assert not priority_provider.complete.called, ( - "Must NOT silently fall back to the priority provider when an " - "explicitly-configured model_role fails to resolve" + assert priority_provider.complete.called, ( + "Must fall back to the priority provider when an explicitly-" + "configured model_role resolves to no candidates, rather than " + "silently skipping naming for the turn" + ) + call_kwargs = priority_provider.complete.call_args + request = call_kwargs[0][0] + assert request.model is None, ( + "Fallback must not invent a model override -- it uses whatever " + "model the fallback provider is already configured with" ) resolver.resolve.assert_called_once() + warnings = [r for r in caplog.records if r.levelno >= 30] + assert warnings, ( + "Expected a WARNING log identifying the unresolved role and the " + "fallback provider substituted for it" + ) + assert any("fast" in r.getMessage() for r in warnings), ( + "Warning should name the model_role that failed to resolve" + ) + assert any("provider-priority" in r.getMessage() for r in warnings), ( + "Warning should name the provider actually used" + ) + + @pytest.mark.asyncio + async def test_resolver_empty_result_warns_once_per_session(self, caplog) -> None: + """The no-candidates fallback warning fires once per session, then + drops to DEBUG on subsequent occurrences within the same session. + + Naming retries every few turns for the life of a session, so without + this, a stable config gap (role never resolves) would re-emit the + identical WARNING on every retry -- noise that drowns out the one + occurrence a reader actually needs to see. + """ + providers = {"provider-priority": _make_mock_provider()} + resolver = _make_resolver(return_value=[]) + hook = _make_hook( + providers=providers, + model_role_resolver=resolver, + model_role="fast", + ) + + with caplog.at_level("DEBUG"): + await hook._call_provider("name this session", "session-xyz") + first_pass_warnings = [r for r in caplog.records if r.levelno >= 30] + caplog.clear() + await hook._call_provider("name this session", "session-xyz") + second_pass_warnings = [r for r in caplog.records if r.levelno >= 30] + second_pass_debugs = [r for r in caplog.records if r.levelno == 10] + + assert first_pass_warnings, "First occurrence in a session must warn" + assert not second_pass_warnings, ( + "Second occurrence in the SAME session must not re-warn" + ) + assert second_pass_debugs, ( + "Second occurrence should still be logged, just at DEBUG" + ) + @pytest.mark.asyncio async def test_resolver_exception_aborts_without_calling_provider(self) -> None: """Resolver present but resolve() raises must abort, NOT propagate and @@ -434,7 +496,7 @@ async def test_resolver_exception_aborts_without_calling_provider(self) -> None: @pytest.mark.asyncio async def test_resolver_empty_result_logs_warning(self, caplog) -> None: - """Aborting due to an empty resolution must be logged at WARNING.""" + """Falling back due to an empty resolution must be logged at WARNING.""" hook = _make_hook( providers={"provider-priority": _make_mock_provider()}, model_role_resolver=_make_resolver(return_value=[]), @@ -442,7 +504,7 @@ async def test_resolver_empty_result_logs_warning(self, caplog) -> None: ) with caplog.at_level("WARNING"): - await hook._call_provider("name this session") + await hook._call_provider("name this session", "session-1") warnings = [r for r in caplog.records if r.levelno >= 30] assert warnings, (