fix: log primary model error before fallback

nanobot/providers/fallback_provider.py

@@ -150,13 +150,17 @@ class FallbackProvider(LLMProvider):
         on_stream_recover: Callable[[], Awaitable[None]] | None = None,
     ) -> LLMResponse:
         primary_model = kwargs.get("model") or self._primary.get_default_model()
+        primary_was_attempted = False
+        primary_error = "unknown error"
 
         if self._primary_available():
+            primary_was_attempted = True
             response = await call(self._primary, kwargs)
             if response.finish_reason != "error":
                 self._primary_failures = 0
                 self._primary_tripped_at = None
                 return response
+            primary_error = (response.content or primary_error)[:120]
 
             if has_streamed is not None and has_streamed[0]:
                 is_timeout = (response.error_kind or "").lower() == "timeout"
@@ -196,7 +200,7 @@ class FallbackProvider(LLMProvider):
             logger.debug("Primary model '{}' circuit open; skipping", primary_model)
 
         last_response: LLMResponse | None = None
-        primary_skipped = not self._primary_available()
+        primary_skipped = not primary_was_attempted
         for idx, fallback in enumerate(self._fallback_presets):
             fallback_model = fallback.model
             if has_streamed is not None and has_streamed[0]:
@@ -221,8 +225,8 @@ class FallbackProvider(LLMProvider):
                 )
             elif idx == 0:
                 logger.info(
-                    "Primary model '{}' failed, trying fallback '{}'",
-                    primary_model, fallback_model,
+                    "Primary model '{}' failed: {}; trying fallback '{}'",
+                    primary_model, primary_error, fallback_model,
                 )
             else:
                 logger.info(

tests/agent/test_runner_fallback.py

@@ -6,6 +6,7 @@ from typing import Any
 from unittest.mock import MagicMock, patch
 
 import pytest
+from loguru import logger
 
 from nanobot.config.schema import ModelPresetConfig
 from nanobot.providers.base import LLMProvider, LLMResponse
@@ -284,6 +285,30 @@ class TestFallbackOnPrimaryError:
         assert primary.chat_calls[0]["model"] == "primary-model"
         assert fallback.chat_calls[0]["model"] == "fallback-a"
 
+    @pytest.mark.asyncio
+    async def test_logs_primary_error_before_fallback(self) -> None:
+        primary = _FakeProvider("primary", _error_response("primary overloaded"))
+        fallback = _FakeProvider("fallback", _make_response("fallback ok"))
+        factory = MagicMock(return_value=fallback)
+        logs: list[str] = []
+        sink_id = logger.add(lambda message: logs.append(str(message)), format="{message}")
+
+        try:
+            fb = FallbackProvider(
+                primary=primary,
+                fallback_presets=[_fallback("fallback-a")],
+                provider_factory=factory,
+            )
+            await fb.chat(messages=[{"role": "user", "content": "hi"}], model="primary-model")
+        finally:
+            logger.remove(sink_id)
+
+        assert any(
+            "Primary model 'primary-model' failed: primary overloaded; trying fallback 'fallback-a'"
+            in line
+            for line in logs
+        )
+
 
 class TestNoFallbackWhenContentStreamed:
     @pytest.mark.asyncio