From 72410f6cf9a5c2f3eeb333f82c24d707076983a5 Mon Sep 17 00:00:00 2001 From: anay Date: Sun, 19 Jul 2026 13:33:22 -0700 Subject: [PATCH] fix: surface the real cause when outfit suggestion AI response is truncated MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Fixes #139. The user's attached backend/LM Studio logs show the actual failure: the model (a reasoning-capable Qwen3 build) put its whole chain-of-thought in `reasoning_content`, exhausted the completion token budget doing so, and returned `content: ""` with `finish_reason: "length"`. `_parse_ai_response` then failed to parse the empty string as JSON, and that failure was swallowed by a broad `except Exception` into the generic "AI service is not available. Please check your AI endpoint configuration in Settings." — which is misleading, since the endpoint responded successfully and is correctly configured; it just never emitted any output content. `AIService.generate_text()` now detects this empty-content/finish_reason case right after extracting the response and raises a new `AIResponseTruncatedError` with the specific cause (reasoning consumed the budget vs. some other truncation) and an actionable hint (raise AI_MAX_TOKENS or disable extended thinking for the model). It retries across the existing retry loop before giving up, since the failure is non-deterministic (depends on how long the model reasons). In `RecommendationService.generate_recommendation`, this error type is now caught explicitly and re-raised with its original, specific message instead of being caught by the generic fallback handler. Reproduced with a unit test built from the exact response payload shape in the issue's attached logs (empty content + reasoning_content + finish_reason "length"); also confirmed the app's error text is not a literal "An error has occured" string anywhere in the codebase, so the issue title is the reporter's paraphrase rather than a literal typo to fix. pairing_service.py has an analogous parsing/error-swallowing pattern but is intentionally left untouched here — it's a separate feature (see #140) and out of scope for this fix. --- backend/app/services/ai_service.py | 41 ++++++++- .../app/services/recommendation_service.py | 8 +- backend/tests/test_ai_service.py | 87 ++++++++++++++++++- 3 files changed, 133 insertions(+), 3 deletions(-) diff --git a/backend/app/services/ai_service.py b/backend/app/services/ai_service.py index c3f9a632..730dc722 100644 --- a/backend/app/services/ai_service.py +++ b/backend/app/services/ai_service.py @@ -661,7 +661,33 @@ async def generate_text( data = response.json() used_model = data.get("model", endpoint.text_model) - content = data["choices"][0]["message"]["content"] + choice = data["choices"][0] + message = choice["message"] + content = message["content"] + + if not content or not content.strip(): + finish_reason = choice.get("finish_reason") + reasoning = message.get("reasoning_content") + if finish_reason == "length" and reasoning: + detail = ( + "its reasoning/thinking output consumed the entire " + "completion token budget before it produced a response" + ) + elif finish_reason == "length": + detail = "the response was cut off before any content was generated" + else: + detail = f"finish_reason={finish_reason!r}" + last_error = AIResponseTruncatedError( + f"{endpoint.name} (model: {used_model}) returned an empty " + f"response: {detail}. Try raising AI_MAX_TOKENS (currently " + f"{self.settings.ai_max_tokens}) or disabling extended " + "thinking/reasoning mode for this model." + ) + logger.warning(str(last_error)) + if attempt < self.settings.ai_max_retries - 1: + continue + break + logger.info( f"Text generation successful via {endpoint.name} (model: {used_model})" ) @@ -690,6 +716,19 @@ async def generate_text( raise RuntimeError("Failed to generate text - no endpoints available") +class AIResponseTruncatedError(RuntimeError): + """Raised when a model's response was cut off before it produced any output content. + + Reasoning-capable models (e.g. Qwen3, DeepSeek-R1) return their chain-of-thought in a + separate ``reasoning_content`` field, distinct from ``content``. If that reasoning + consumes the entire completion token budget, the API reports ``finish_reason == + "length"`` with an empty ``content`` string. Downstream JSON parsing of an empty + string then fails with an unhelpful message, which used to get swallowed into a + generic "AI service is not available" error even though the endpoint responded + successfully. This error preserves the real cause so callers can surface it. + """ + + class AIDisabledError(RuntimeError): """Raised when an internal AI client is requested while that capability is off.""" diff --git a/backend/app/services/recommendation_service.py b/backend/app/services/recommendation_service.py index 441038ab..35719cc9 100644 --- a/backend/app/services/recommendation_service.py +++ b/backend/app/services/recommendation_service.py @@ -22,7 +22,7 @@ ) from app.models.preference import UserPreference from app.models.user import User -from app.services.ai_service import AIService, require_internal_ai +from app.services.ai_service import AIResponseTruncatedError, AIService, require_internal_ai from app.services.item_scorer import get_season, score_items from app.services.suggestion_cache import pop_suggestion, push_suggestions from app.services.weather_service import ( @@ -884,6 +884,12 @@ async def generate_recommendation( except AIRecommendationError: raise + except AIResponseTruncatedError as e: + # Preserve the specific, actionable cause instead of the generic message + # below — the AI endpoint responded successfully, it just didn't produce + # any output content (see AIResponseTruncatedError for why). + logger.error(f"AI recommendation failed: {e}") + raise AIRecommendationError(str(e)) from e except Exception as e: logger.error(f"AI recommendation failed: {e}") raise AIRecommendationError( diff --git a/backend/tests/test_ai_service.py b/backend/tests/test_ai_service.py index 3007328e..ab772c9a 100644 --- a/backend/tests/test_ai_service.py +++ b/backend/tests/test_ai_service.py @@ -1,4 +1,15 @@ -from app.services.ai_service import AIService, ClothingTags +from unittest.mock import patch + +import httpx +import pytest + +from app.services.ai_service import AIResponseTruncatedError, AIService, ClothingTags + +FAKE_REQUEST = httpx.Request("POST", "http://ai-endpoint.test/chat/completions") + + +def _mock_response(json_data: dict, status_code: int = 200) -> httpx.Response: + return httpx.Response(status_code, json=json_data, request=FAKE_REQUEST) class TestTagParsing: @@ -166,3 +177,77 @@ def test_full_construction(self): assert tags.primary_color == "navy" assert len(tags.colors) == 2 assert tags.confidence == 0.92 + + +class TestGenerateTextTruncatedResponse: + """Regression tests for issue #139: reasoning-capable models (e.g. Qwen3 via + + LM Studio) can exhaust the entire completion token budget on their + ``reasoning_content`` chain-of-thought, leaving ``message.content`` empty with + ``finish_reason == "length"``. That used to surface as an opaque "Could not parse + AI response as JSON: " error, further masked upstream as a generic "AI service is + not available" message. It should now raise AIResponseTruncatedError with the real + cause, every retry attempt, so callers can tell the user what actually happened. + """ + + @staticmethod + def _truncated_reasoning_response() -> dict: + # Mirrors the exact shape reported in the issue's attached LM Studio / + # backend logs: assistant content is empty, the model's chain-of-thought + # landed in reasoning_content instead, and finish_reason is "length". + return { + "id": "chatcmpl-j0ue2a2xp0kziw0f8gof", + "object": "chat.completion", + "model": "qwen/qwen3.5-9b", + "choices": [ + { + "index": 0, + "message": { + "role": "assistant", + "content": "", + "reasoning_content": "The user wants me to create 3 outfits...", + "tool_calls": [], + }, + "finish_reason": "length", + } + ], + "usage": {"prompt_tokens": 3417, "completion_tokens": 4775, "total_tokens": 8192}, + } + + @pytest.mark.asyncio + async def test_empty_content_with_reasoning_raises_truncated_error(self): + service = AIService() + mock_response = _mock_response(self._truncated_reasoning_response()) + + with patch("httpx.AsyncClient.post", return_value=mock_response): + with pytest.raises(AIResponseTruncatedError) as exc_info: + await service.generate_text("suggest an outfit") + + message = str(exc_info.value) + assert "reasoning" in message + assert "AI_MAX_TOKENS" in message + + @pytest.mark.asyncio + async def test_empty_content_without_reasoning_still_raises_truncated_error(self): + service = AIService() + payload = self._truncated_reasoning_response() + del payload["choices"][0]["message"]["reasoning_content"] + mock_response = _mock_response(payload) + + with patch("httpx.AsyncClient.post", return_value=mock_response): + with pytest.raises(AIResponseTruncatedError): + await service.generate_text("suggest an outfit") + + @pytest.mark.asyncio + async def test_normal_response_is_unaffected(self): + service = AIService() + payload = self._truncated_reasoning_response() + payload["choices"][0]["message"]["content"] = '{"outfits": []}' + payload["choices"][0]["message"]["reasoning_content"] = "" + payload["choices"][0]["finish_reason"] = "stop" + mock_response = _mock_response(payload) + + with patch("httpx.AsyncClient.post", return_value=mock_response): + content = await service.generate_text("suggest an outfit") + + assert content == '{"outfits": []}'