perf(chat-api): 补充聊天接口追踪并异步化图片读取

- 新增后端 perf trace 工具，覆盖会话、消息、头像和图片接口
- 将图片路径探测、候选收集、解密读取与缓存写入移入线程，减少阻塞
- 补充缓存命中与候选选择追踪，并为图片接口增加 prefer_live

Author: 2977094657

src/wechat_decrypt_tool/perf_trace.py

@@ -0,0 +1,30 @@
+from __future__ import annotations
+
+import json
+import threading
+import time
+from typing import Any, Callable
+
+
+def create_perf_trace(logger: Any, category: str, **base_fields: Any) -> tuple[str, Callable[[str], None]]:
+    trace_id = f"{category}-{int(time.time() * 1000)}-{threading.get_ident()}"
+    started_at = time.perf_counter()
+    last_at = started_at
+
+    def log(phase: str, **fields: Any) -> None:
+        nonlocal last_at
+        now = time.perf_counter()
+        payload = {
+            **base_fields,
+            **fields,
+            "elapsedMs": round((now - started_at) * 1000.0, 1),
+            "deltaMs": round((now - last_at) * 1000.0, 1),
+        }
+        last_at = now
+        try:
+            payload_text = json.dumps(payload, ensure_ascii=False, default=str)
+        except Exception:
+            payload_text = str(payload)
+        logger.info("[%s] %s %s %s", trace_id, category, phase, payload_text)
+
+    return trace_id, log

src/wechat_decrypt_tool/routers/chat.py

@@ -73,6 +73,7 @@
 from ..database_filters import list_countable_database_names
 from ..key_store import remove_account_keys_from_store
 from ..path_fix import PathFixRoute
+from ..perf_trace import create_perf_trace
 from ..session_last_message import (
     build_session_last_message_table,
     get_session_last_message_status,
@@ -3998,6 +3999,17 @@ def list_chat_sessions(
     contact_db_path = account_dir / "contact.db"
     head_image_db_path = account_dir / "head_image.db"
     base_url = str(request.base_url).rstrip("/")
+    _trace_id, trace = create_perf_trace(
+        logger,
+        "chat.sessions",
+        account=account_dir.name,
+        source=source_norm or "default",
+        limit=int(limit),
+        includeHidden=bool(include_hidden),
+        includeOfficial=bool(include_official),
+        preview=str(preview or ""),
+    )
+    trace("request:start")
 
     rt_conn = None
     rows: list[Any]
@@ -4122,6 +4134,12 @@ def _ts(v: Any) -> int:
         finally:
             sconn.close()
 
+    trace(
+        "rows:loaded",
+        rawCount=len(rows or []),
+        realtime=bool(source_norm == "realtime"),
+    )
+
     filtered: list[Any] = []
     for r in rows:
         username = _session_row_get(r, "username", "") or ""
@@ -4133,8 +4151,18 @@ def _ts(v: Any) -> int:
             continue
         filtered.append(r)
 
+    trace(
+        "rows:filtered",
+        filteredCount=len(filtered),
+    )
+
     raw_usernames = [str(_session_row_get(r, "username", "") or "").strip() for r in filtered]
     top_flags = _load_contact_top_flags(contact_db_path, raw_usernames)
+    trace(
+        "top-flags:loaded",
+        usernameCount=len(raw_usernames),
+        topCount=sum(1 for value in top_flags.values() if value),
+    )
 
     def _to_int(v: Any) -> int:
         try:
@@ -4164,6 +4192,12 @@ def _session_sort_key(row: Any) -> tuple[int, int, int]:
 
     contact_rows = _load_contact_rows(contact_db_path, usernames)
     local_avatar_usernames = _query_head_image_usernames(head_image_db_path, usernames)
+    trace(
+        "contacts:loaded",
+        usernameCount=len(usernames),
+        contactRowCount=len(contact_rows),
+        localAvatarCount=len(local_avatar_usernames),
+    )
 
     # Some sessions (notably enterprise groups / openim-related IDs) may be missing from decrypted contact.db
     # (or lack nickname/avatar columns). In that case, fall back to WCDB APIs (same as WeFlow) to resolve
@@ -4212,6 +4246,12 @@ def _session_sort_key(row: Any) -> tuple[int, int, int]:
         wcdb_display_names = {}
         wcdb_avatar_urls = {}
 
+    trace(
+        "wcdb-fallback:loaded",
+        displayNameCount=len(wcdb_display_names),
+        avatarUrlCount=len(wcdb_avatar_urls),
+    )
+
     preview_mode = str(preview or "").strip().lower()
     if preview_mode not in {"latest", "index", "session", "db", "none"}:
         preview_mode = "latest"
@@ -4299,6 +4339,14 @@ def _is_generic_location_preview(value: Any) -> bool:
         except Exception:
             pass
 
+    trace(
+        "previews:resolved",
+        previewMode=preview_mode,
+        previewCount=len(last_previews),
+        groupSenderDisplayCount=len(group_sender_display_names),
+        unresolvedGroupSenderCount=len(unresolved),
+    )
+
     sessions: list[dict[str, Any]] = []
     for r in filtered:
         username = r["username"]
@@ -4416,6 +4464,10 @@ def _is_generic_location_preview(value: Any) -> bool:
             }
         )
 
+    trace(
+        "response:ready",
+        sessionCount=len(sessions),
+    )
     return {
         "status": "success",
         "account": account_dir.name,
@@ -5169,11 +5221,24 @@ def list_chat_messages(
     head_image_db_path = account_dir / "head_image.db"
     message_resource_db_path = account_dir / "message_resource.db"
     base_url = str(request.base_url).rstrip("/")
+    _trace_id, trace = create_perf_trace(
+        logger,
+        "chat.messages",
+        account=account_dir.name,
+        username=username,
+        source=source_norm or "default",
+        limit=int(limit),
+        offset=int(offset),
+        order=str(order or ""),
+        renderTypes=str(render_types or ""),
+    )
+    trace("request:start")
 
     db_paths: list[Path] = []
     if source_norm != "realtime":
         db_paths = _iter_message_db_paths(account_dir)
         if not db_paths:
+            trace("response:error", reason="no-message-dbs")
             return {
                 "status": "error",
                 "account": account_dir.name,
@@ -5199,6 +5264,12 @@ def list_chat_messages(
         resource_conn = None
         resource_chat_id = None
 
+    trace(
+        "resource-db:resolved",
+        hasResourceDb=bool(resource_conn is not None),
+        resourceChatId=int(resource_chat_id or 0),
+    )
+
     want_asc = str(order or "").lower() != "desc"
 
     want_types: Optional[set[str]] = None
@@ -5337,6 +5408,16 @@ def pick(*keys: str) -> Any:
                 break
             scan_take = next_take
 
+    trace(
+        "messages:collected",
+        scanTake=int(scan_take),
+        mergedCount=len(merged),
+        hasMoreAny=bool(has_more_any),
+        senderUsernameCount=len(sender_usernames),
+        quoteUsernameCount=len(quote_usernames),
+        patUsernameCount=len(pat_usernames),
+    )
+
     # Self-heal (default source only): if the decrypted snapshot has no conversation table yet (new session),
     # do a one-shot realtime->decrypted sync and re-query once. This avoids "暂无聊天记录" after turning off realtime.
     if (
@@ -5352,6 +5433,7 @@ def pick(*keys: str) -> Any:
             missing_table = True
 
         if missing_table:
+            trace("self-heal:missing-table")
             rt_conn2 = None
             try:
                 rt_conn2 = WCDB_REALTIME.ensure_connected(account_dir)
@@ -5362,6 +5444,7 @@ def pick(*keys: str) -> Any:
 
             if rt_conn2 is not None:
                 try:
+                    trace("self-heal:sync:start")
                     with _realtime_sync_lock(account_dir.name, username):
                         msg_db_path2, table_name2 = _ensure_decrypted_message_table(account_dir, username)
                         _sync_chat_realtime_messages_for_table(
@@ -5373,7 +5456,9 @@ def pick(*keys: str) -> Any:
                             max_scan=max(200, int(limit) + 50),
                             backfill_limit=0,
                         )
+                    trace("self-heal:sync:end")
                 except Exception:
+                    trace("self-heal:sync:error")
                     pass
 
                 (
@@ -5393,6 +5478,11 @@ def pick(*keys: str) -> Any:
                 )
                 if want_types is not None:
                     merged = [m for m in merged if _normalize_render_type_key(m.get("renderType")) in want_types]
+                trace(
+                    "self-heal:requery:end",
+                    mergedCount=len(merged),
+                    hasMoreAny=bool(has_more_any),
+                )
 
     r"""
     take = int(limit) + int(offset)
@@ -5886,8 +5976,17 @@ def sort_key(m: dict[str, Any]) -> tuple[int, int, int]:
     if want_asc:
         page = list(reversed(page))
 
+    trace(
+        "page:sliced",
+        mergedCount=len(merged),
+        pageCount=len(page),
+        hasMore=bool(has_more_global),
+        orderAsc=bool(want_asc),
+    )
+
     # Hot path optimization: only enrich the page we return.
     if not page:
+        trace("response:ready", pageCount=0)
         return {
             "status": "success",
             "account": account_dir.name,
@@ -5961,6 +6060,12 @@ def sort_key(m: dict[str, Any]) -> tuple[int, int, int]:
     )
     sender_contact_rows = _load_contact_rows(contact_db_path, uniq_senders)
     local_sender_avatars = _query_head_image_usernames(head_image_db_path, uniq_senders)
+    trace(
+        "senders:loaded",
+        uniqSenderCount=len(uniq_senders),
+        senderContactRowCount=len(sender_contact_rows),
+        localSenderAvatarCount=len(local_sender_avatars),
+    )
 
     # contact.db may not include enterprise/openim contacts (or group chatroom records). WCDB has a more complete
     # view of display names + avatar URLs, so we use it as a best-effort fallback.
@@ -5997,6 +6102,12 @@ def sort_key(m: dict[str, Any]) -> tuple[int, int, int]:
         chatroom_id=username,
         sender_usernames=uniq_senders,
     )
+    trace(
+        "sender-fallbacks:loaded",
+        wcdbDisplayNameCount=len(wcdb_display_names),
+        wcdbAvatarUrlCount=len(wcdb_avatar_urls),
+        groupNicknameCount=len(group_nicknames),
+    )
 
     for m in messages_window:
         # If appmsg doesn't provide sourcedisplayname, try mapping sourceusername to display name.
@@ -6155,6 +6266,12 @@ def sort_key(m: dict[str, Any]) -> tuple[int, int, int]:
             wcdb_display_names=wcdb_display_names,
         )
 
+    trace(
+        "response:ready",
+        pageCount=len(page),
+        total=int(offset) + len(page) + (1 if has_more_global else 0),
+        hasMore=bool(has_more_global),
+    )
     return {
         "status": "success",
         "account": account_dir.name,