Improved AI error diagnostics: detailed timeout logging per attempt

- _generate_openrouter: log request start, response time, timeout details
  with httpx.Timeout (connect=15s, rest=AI_REQUEST_TIMEOUT)
- All AI functions: log error_type (exception class name) + truncated error
- _retry_with_backoff: log each attempt with wait time
- Clean rewrite of ai_vision.py

app/services/ai_vision.py

@@ -13,7 +13,6 @@ import re
 import base64
 import time
 import httpx
-import io
 from pathlib import Path
 from typing import Optional, Tuple
 
@@ -26,13 +25,12 @@ from app.services.runtime_config import runtime_ai_config
 
 logger = logging.getLogger(__name__)
 
-# Cache du client Gemini avec TTL (évite de recréer à chaque appel)
+# Cache du client Gemini avec TTL
 _client: Optional[genai.Client] = None
 _client_api_key: Optional[str] = None
 
 
 def _get_client() -> genai.Client:
-    """Retourne un client Gemini. Recrée si la clé API a changé."""
     global _client, _client_api_key
     current_key = settings.GEMINI_API_KEY
     if _client is None or _client_api_key != current_key:
@@ -42,19 +40,13 @@ def _get_client() -> genai.Client:
 
 
 async def _read_image(file_path: str) -> tuple[bytes, str]:
-    """Lit l'image via le StorageBackend et détecte le media_type."""
     path = Path(file_path)
     suffix = path.suffix.lower()
-
     mime_map = {
-        ".jpg": "image/jpeg",
-        ".jpeg": "image/jpeg",
-        ".png": "image/png",
-        ".gif": "image/gif",
-        ".webp": "image/webp",
+        ".jpg": "image/jpeg", ".jpeg": "image/jpeg",
+        ".png": "image/png", ".gif": "image/gif", ".webp": "image/webp",
     }
     media_type = mime_map.get(suffix, "image/jpeg")
-
     backend = get_storage_backend()
     data = await backend.get_bytes(file_path)
     return data, media_type
@@ -81,10 +73,8 @@ def _usage_tokens_gemini(response) -> tuple[Optional[int], Optional[int]]:
 
 
 async def _retry_with_backoff(fn, *args, max_retries=None, **kwargs):
-    """Exécute fn avec retry + backoff exponentiel en cas d'échec."""
     retries = max_retries if max_retries is not None else settings.AI_MAX_RETRIES
     last_error = None
-
     for attempt in range(retries + 1):
         try:
             return await fn(*args, **kwargs)
@@ -92,25 +82,24 @@ async def _retry_with_backoff(fn, *args, max_retries=None, **kwargs):
             last_error = "timeout"
             wait = 2 ** attempt
             logger.warning("ai.retry.timeout", extra={
-                "attempt": attempt + 1,
-                "max_retries": retries,
-                "wait_s": wait,
+                "attempt": attempt + 1, "max_retries": retries, "wait_s": wait,
             })
         except Exception as e:
-            last_error = str(e)
+            last_error = str(e)[:200]
             wait = 2 ** attempt
             logger.warning("ai.retry.error", extra={
-                "attempt": attempt + 1,
-                "max_retries": retries,
-                "wait_s": wait,
-                "error": str(e),
+                "attempt": attempt + 1, "max_retries": retries,
+                "wait_s": wait, "error": str(e)[:200],
             })
         if attempt < retries:
             await asyncio.sleep(wait)
-
     raise Exception(f"AI request failed after {retries + 1} attempts: {last_error}")
 
 
+# ─────────────────────────────────────────────────────────────
+# Google Gemini
+# ─────────────────────────────────────────────────────────────
+
 async def _generate_gemini(
     prompt: str,
     image_bytes: Optional[bytes] = None,
@@ -118,9 +107,7 @@ async def _generate_gemini(
     max_tokens: int = 1024,
     model_override: Optional[str] = None,
 ) -> dict:
-    """Appel à Google Gemini via SDK avec timeout et retry."""
     if not settings.GEMINI_API_KEY:
-        logger.warning("ai.gemini.no_key")
         return {"text": None, "usage": (None, None)}
 
     client = _get_client()
@@ -150,10 +137,16 @@ async def _generate_gemini(
         usage = _usage_tokens_gemini(response)
         return {"text": getattr(response, "text", ""), "usage": usage}
     except Exception as e:
-        logger.error("ai.gemini.error", extra={"error": str(e)})
-        return {"text": None, "usage": (None, None), "error": str(e)}
+        logger.error("ai.gemini.error", extra={
+            "model": model, "error_type": type(e).__name__, "error": str(e)[:300],
+        })
+        return {"text": None, "usage": (None, None), "error": str(e)[:300]}
 
 
+# ─────────────────────────────────────────────────────────────
+# OpenRouter
+# ─────────────────────────────────────────────────────────────
+
 async def _generate_openrouter(
     prompt: str,
     image_bytes: Optional[bytes] = None,
@@ -161,9 +154,7 @@ async def _generate_openrouter(
     max_tokens: int = 1024,
     model_override: Optional[str] = None,
 ) -> dict:
-    """Appel à OpenRouter via HTTP avec timeout et retry."""
     if not settings.OPENROUTER_API_KEY:
-        logger.warning("ai.openrouter.no_key")
         return {"text": None, "usage": (None, None)}
 
     model = model_override or runtime_ai_config.model or settings.OPENROUTER_MODEL
@@ -171,23 +162,18 @@ async def _generate_openrouter(
     headers = {
         "Authorization": f"Bearer {settings.OPENROUTER_API_KEY}",
         "Content-Type": "application/json",
-        "HTTP-Referer": settings.HOST,
+        "HTTP-Referer": "imago-pipeline",
         "X-Title": settings.APP_NAME,
     }
 
     messages = []
-    content_payload = []
-    content_payload.append({"type": "text", "text": prompt})
-
+    content_payload = [{"type": "text", "text": prompt}]
     if image_bytes and media_type:
         b64_img = base64.b64encode(image_bytes).decode("utf-8")
         content_payload.append({
             "type": "image_url",
-            "image_url": {
-                "url": f"data:{media_type};base64,{b64_img}"
-            }
+            "image_url": {"url": f"data:{media_type};base64,{b64_img}"}
         })
-
     messages.append({"role": "user", "content": content_payload})
 
     payload = {
@@ -197,34 +183,58 @@ async def _generate_openrouter(
         "response_format": {"type": "json_object"}
     }
 
+    timeout_secs = settings.AI_REQUEST_TIMEOUT
+    logger.info("ai.openrouter.request", extra={
+        "model": model, "timeout_s": timeout_secs,
+        "image_bytes": len(image_bytes) if image_bytes else 0,
+    })
+
     async def _call():
-        async with httpx.AsyncClient() as client:
-            response = await client.post(
-                "https://openrouter.ai/api/v1/chat/completions",
-                json=payload,
-                headers=headers,
-                timeout=settings.AI_REQUEST_TIMEOUT,
-            )
-            response.raise_for_status()
-            return response.json()
+        t0 = time.time()
+        try:
+            async with httpx.AsyncClient(
+                timeout=httpx.Timeout(timeout_secs, connect=15.0)
+            ) as client:
+                response = await client.post(
+                    "https://openrouter.ai/api/v1/chat/completions",
+                    json=payload,
+                    headers=headers,
+                )
+                elapsed = time.time() - t0
+                logger.info("ai.openrouter.response", extra={
+                    "status": response.status_code, "elapsed_s": round(elapsed, 1),
+                })
+                response.raise_for_status()
+                return response.json()
+        except httpx.TimeoutException as e:
+            elapsed = time.time() - t0
+            logger.error("ai.openrouter.timeout", extra={
+                "elapsed_s": round(elapsed, 1),
+                "timeout_setting": timeout_secs,
+                "detail": str(e),
+            })
+            raise
 
     try:
         data = await _retry_with_backoff(_call)
         text = ""
         if "choices" in data and len(data["choices"]) > 0:
             text = data["choices"][0]["message"]["content"]
-
         usage_data = data.get("usage", {})
         prompt_tokens = usage_data.get("prompt_tokens")
         output_tokens = usage_data.get("completion_tokens")
-
         return {"text": text, "usage": (prompt_tokens, output_tokens)}
-
     except Exception as e:
-        logger.error("ai.openrouter.error", extra={"error": str(e)})
-        return {"text": None, "usage": (None, None), "error": str(e)}
+        logger.error("ai.openrouter.final_error", extra={
+            "model": model, "error_type": type(e).__name__, "error": str(e)[:300],
+        })
+        return {"text": None, "usage": (None, None), "error": str(e)[:300]}
 
 
+# ─────────────────────────────────────────────────────────────
+# Dispatcher
+# ─────────────────────────────────────────────────────────────
+
 async def _generate(
     prompt: str,
     image_bytes: Optional[bytes] = None,
@@ -233,7 +243,6 @@ async def _generate(
     provider_override: Optional[str] = None,
     model_override: Optional[str] = None,
 ) -> dict:
-    """Dispatcher vers le bon provider, avec override optionnel par client."""
     provider = provider_override or runtime_ai_config.provider or settings.AI_PROVIDER.lower()
     logger.info("ai.generate", extra={"provider": provider})
 
@@ -249,6 +258,10 @@ async def _generate(
         )
 
 
+# ─────────────────────────────────────────────────────────────
+# Fonctions publiques
+# ─────────────────────────────────────────────────────────────
+
 def _build_prompt(ocr_hint: Optional[str], language: str) -> str:
     ocr_section = ""
     if ocr_hint and len(ocr_hint.strip()) > 5:
@@ -258,7 +271,6 @@ Texte détecté dans l'image par OCR (utilise-le pour enrichir ta réponse) :
 {ocr_hint[:500]}
 \"\"\"
 """
-
     return f"""Analyse cette image avec précision et retourne UNIQUEMENT un objet JSON valide avec ces champs :
 
 {{
@@ -283,10 +295,6 @@ async def analyze_image(
     provider_override: Optional[str] = None,
     model_override: Optional[str] = None,
 ) -> dict:
-    """
-    Envoie l'image à l'AI pour analyse (Description + Tags).
-    Supporte l'override par client pour le fournisseur/modèle.
-    """
     if not settings.AI_ENABLED:
         return {}
 
@@ -297,12 +305,8 @@ async def analyze_image(
     )
 
     result = {
-        "description": None,
-        "tags": [],
-        "confidence": None,
-        "model": active_model,
-        "prompt_tokens": None,
-        "output_tokens": None,
+        "description": None, "tags": [], "confidence": None,
+        "model": active_model, "prompt_tokens": None, "output_tokens": None,
     }
 
     try:
@@ -310,12 +314,9 @@ async def analyze_image(
         prompt = _build_prompt(ocr_hint, language)
 
         response = await _generate(
-            prompt=prompt,
-            image_bytes=image_bytes,
-            media_type=media_type,
+            prompt=prompt, image_bytes=image_bytes, media_type=media_type,
             max_tokens=settings.GEMINI_MAX_TOKENS,
-            provider_override=provider_override,
-            model_override=model_override,
+            provider_override=provider_override, model_override=model_override,
         )
 
         text = response.get("text")
@@ -340,17 +341,10 @@ async def analyze_image(
 
 
 async def extract_text_with_ai(file_path: str) -> dict:
-    """
-    Utilise l'AI comme fallback OCR.
-    """
     result = {
-        "text": None,
-        "has_text": False,
-        "language": "unknown",
-        "confidence": 0.0,
-        "method": f"ai-{settings.AI_PROVIDER}"
+        "text": None, "has_text": False, "language": "unknown",
+        "confidence": 0.0, "method": f"ai-{settings.AI_PROVIDER}"
     }
-
     if not settings.AI_ENABLED:
         return result
 
@@ -368,11 +362,8 @@ Retourne UNIQUEMENT un objet JSON :
 }
 Si aucun texte n'est visible, retourne : {"text": "", "has_text": false}
 """
-
         response = await _generate(
-            prompt=prompt,
-            image_bytes=image_bytes,
-            media_type=media_type,
+            prompt=prompt, image_bytes=image_bytes, media_type=media_type,
             max_tokens=1024
         )
 
@@ -390,7 +381,6 @@ Si aucun texte n'est visible, retourne : {"text": "", "has_text": false}
                 logger.warning("ai.ocr.json_parse_failed")
         else:
             logger.info("ai.ocr.empty_response")
-
     except Exception as e:
         logger.error("ai.ocr.error", extra={"error": str(e)})
 
@@ -398,15 +388,10 @@ Si aucun texte n'est visible, retourne : {"text": "", "has_text": false}
 
 
 async def summarize_url(url: str, content: str, language: str = "français") -> dict:
-    """Génère un résumé et des tags pour un contenu web."""
     result = {
-        "summary": "",
-        "tags": [],
-        "model": settings.AI_PROVIDER,
-        "prompt_tokens": None,
-        "output_tokens": None,
+        "summary": "", "tags": [], "model": settings.AI_PROVIDER,
+        "prompt_tokens": None, "output_tokens": None,
     }
-
     if not settings.AI_ENABLED:
         return result
 
@@ -426,11 +411,7 @@ Retourne UNIQUEMENT ce JSON :
 }}"""
 
     try:
-        response = await _generate(
-            prompt=prompt,
-            max_tokens=settings.GEMINI_MAX_TOKENS
-        )
-
+        response = await _generate(prompt=prompt, max_tokens=settings.GEMINI_MAX_TOKENS)
         text = response.get("text")
         if text:
             parsed = _extract_json(text)
@@ -438,7 +419,6 @@ Retourne UNIQUEMENT ce JSON :
                 result["summary"] = parsed.get("summary", "")
                 result["tags"] = parsed.get("tags", [])
                 result["prompt_tokens"], result["output_tokens"] = response.get("usage")
-
     except Exception as e:
         logger.error("ai.summarize_url.error", extra={"error": str(e)})
 
@@ -446,18 +426,11 @@ Retourne UNIQUEMENT ce JSON :
 
 
 async def draft_task(description: str, context: Optional[str], language: str = "français") -> dict:
-    """Génère une tâche structurée à partir d'une description."""
     result = {
-        "title": "",
-        "description": "",
-        "steps": [],
-        "estimated_time": None,
-        "priority": None,
-        "model": settings.AI_PROVIDER,
-        "prompt_tokens": None,
-        "output_tokens": None,
+        "title": "", "description": "", "steps": [],
+        "estimated_time": None, "priority": None,
+        "model": settings.AI_PROVIDER, "prompt_tokens": None, "output_tokens": None,
     }
-
     if not settings.AI_ENABLED:
         return result
 
@@ -476,18 +449,13 @@ Retourne UNIQUEMENT ce JSON :
 }}"""
 
     try:
-        response = await _generate(
-            prompt=prompt,
-            max_tokens=settings.GEMINI_MAX_TOKENS
-        )
-
+        response = await _generate(prompt=prompt, max_tokens=settings.GEMINI_MAX_TOKENS)
         text = response.get("text")
         if text:
             parsed = _extract_json(text)
             if parsed:
                 result.update(parsed)
                 result["prompt_tokens"], result["output_tokens"] = response.get("usage")
-
     except Exception as e:
         logger.error("ai.draft_task.error", extra={"error": str(e)})