feat(observability): 豆包 LLM/VLM/Seedream/信任链加 elapsed 耗时日志 (#2171)

Co-authored-by: xiaoxia <dev@xiaoxiajianji.com>
Co-committed-by: xiaoxia <dev@xiaoxiajianji.com>

packages/shared/ai_client.py

@@ -267,6 +267,7 @@ class DoubaoClient:
         }
 
         last_error: Optional[Exception] = None
+        _t0 = time.time()
         for attempt in range(self.max_retries + 1):
             try:
                 response = httpx.post(
@@ -278,21 +279,31 @@ class DoubaoClient:
                 response.raise_for_status()
                 data = response.json()
                 content = data["choices"][0]["message"]["content"]
+                _elapsed = time.time() - _t0
+                logger.info(
+                    "[doubao] chat_completion 完成 model=%s tokens_in=%d tokens_out=%d elapsed=%.1fs attempt=%d",
+                    payload.get("model"),
+                    data.get("usage", {}).get("prompt_tokens", 0),
+                    data.get("usage", {}).get("completion_tokens", 0),
+                    _elapsed,
+                    attempt + 1,
+                )
                 return content.strip()
             except Exception as e:
                 last_error = e
                 if attempt < self.max_retries:
                     wait = 0.5 * (2**attempt)
                     logger.warning(
-                        "豆包API调用失败，%.1fs后重试 (第%d/%d次): %s",
+                        "豆包API调用失败，%.1fs后重试 (第%d/%d次, elapsed=%.1fs): %s",
                         wait,
                         attempt + 1,
                         self.max_retries + 1,
+                        time.time() - _t0,
                         e,
                     )
                     time.sleep(wait)
 
-        logger.error("豆包API调用最终失败: %s", last_error)
+        logger.error("豆包API调用最终失败: elapsed=%.1fs err=%s", time.time() - _t0, last_error)
         return None
 
     def vision_completion(
@@ -361,6 +372,7 @@ class DoubaoClient:
 
         req_timeout = timeout or self.timeout
         last_error: Optional[Exception] = None
+        _t0 = time.time()
         for attempt in range(self.max_retries + 1):
             try:
                 response = httpx.post(
@@ -372,21 +384,31 @@ class DoubaoClient:
                 response.raise_for_status()
                 data = response.json()
                 content = data["choices"][0]["message"]["content"]
+                _elapsed = time.time() - _t0
+                logger.info(
+                    "[doubao] vision_completion 完成 model=%s tokens_in=%d tokens_out=%d elapsed=%.1fs attempt=%d",
+                    payload.get("model"),
+                    data.get("usage", {}).get("prompt_tokens", 0),
+                    data.get("usage", {}).get("completion_tokens", 0),
+                    _elapsed,
+                    attempt + 1,
+                )
                 return content.strip()
             except Exception as e:
                 last_error = e
                 if attempt < self.max_retries:
                     wait = 0.5 * (2**attempt)
                     logger.warning(
-                        "豆包视觉API调用失败，%.1fs后重试 (第%d/%d次): %s",
+                        "豆包视觉API调用失败，%.1fs后重试 (第%d/%d次, elapsed=%.1fs): %s",
                         wait,
                         attempt + 1,
                         self.max_retries + 1,
+                        time.time() - _t0,
                         e,
                     )
                     time.sleep(wait)
 
-        logger.error("豆包视觉API调用最终失败: %s", last_error)
+        logger.error("豆包视觉API调用最终失败: elapsed=%.1fs err=%s", time.time() - _t0, last_error)
         return None
 
     # ── 视频生成（Seedance 2.5，异步任务）────────────────────────────
@@ -508,6 +530,7 @@ class DoubaoClient:
                     raw_portrait_urls.append(u)
             if raw_portrait_urls:
                 trusted_urls: list[str] = []
+                _tc_t0 = time.time()
                 for idx, raw_url in enumerate(raw_portrait_urls):
                     sd_prompt = (
                         seedream_prompt if len(raw_portrait_urls) == 1 else f"{seedream_prompt}（这是参考图{idx + 1}）"
@@ -536,15 +559,17 @@ class DoubaoClient:
                     else:
                         ref_imgs = trusted_urls
                     logger.info(
-                        "[trust-chain] Seedream AI 化完成 %d 张，替换为 reference_image 模式",
+                        "[trust-chain] Seedream AI 化完成 %d 张，总耗时 %.1fs，替换为 reference_image 模式",
                         len(trusted_urls),
+                        time.time() - _tc_t0,
                     )
                 else:
                     # Seedream 部分失败 → 回退原图直传（仍可能被 50411 拦截，但保留降级路径）
                     logger.warning(
-                        "[trust-chain] Seedream AI 化不完整(%d/%d)，回退原图直传",
+                        "[trust-chain] Seedream AI 化不完整(%d/%d)，总耗时 %.1fs，回退原图直传",
                         len(trusted_urls),
                         len(raw_portrait_urls),
+                        time.time() - _tc_t0,
                     )
         # ─────────────────────────────────────────────────────────────────
 
@@ -918,6 +943,7 @@ class DoubaoClient:
         last_err: Exception | None = None
         last_sc = 0
         last_body = ""
+        _img_t0 = time.time()
         for attempt in range(self.max_retries + 1):
             try:
                 resp = httpx.post(url, headers=headers, json=payload, timeout=req_timeout)
@@ -940,10 +966,12 @@ class DoubaoClient:
                     img_url = item.get("url")
                     if img_url:
                         logger.info(
-                            "Seedream 图片生成成功 model=%s ref_imgs=%d size=%s",
+                            "Seedream 图片生成成功 model=%s ref_imgs=%d size=%s elapsed=%.1fs attempt=%d",
                             img_model,
                             len(ref_imgs_local),
                             size,
+                            time.time() - _img_t0,
+                            attempt + 1,
                         )
                         return {"url": img_url, "usage": data.get("usage")}
                 last_err = RuntimeError(f"Seedream 返回结构异常: {str(data)[:300]}")
@@ -999,7 +1027,12 @@ class DoubaoClient:
             "model": img_model,
         }
         logger.error(
-            "Seedream 图片生成最终失败: model=%s status=%d code=%s err=%s", img_model, last_sc, err_code, last_err
+            "Seedream 图片生成最终失败: model=%s status=%d code=%s elapsed=%.1fs err=%s",
+            img_model,
+            last_sc,
+            err_code,
+            time.time() - _img_t0,
+            last_err,
         )
         return None