添加详细日志: 在关键节点加日志以便定位卡住问题

backend/app/main_graph/nodes/rag_nodes.py

@@ -45,7 +45,7 @@ def _get_rag_tool() -> Optional[callable]:
 
 # ========== RAG 检索核心逻辑 ==========
 async def _rag_retrieve_core(state: MainGraphState, pipeline) -> MainGraphState:
-    """执行 RAG 检索的核心逻辑"""
+    info(f"[RAG Core] _rag_retrieve_core 开始")
     retrieval_query = state.user_query
 
     # 优先使用推理结果中的优化查询 - 从新的结构化字段获取
@@ -55,9 +55,14 @@ async def _rag_retrieve_core(state: MainGraphState, pipeline) -> MainGraphState:
         if cfg and cfg.retrieval_query:
             retrieval_query = cfg.retrieval_query
 
+    info(f"[RAG Core] 使用检索查询: {retrieval_query[:50]}...")
     # 直接调用 pipeline 获取文档和上下文
+    info(f"[RAG Core] 调用 pipeline.aretrieve")
     documents = await pipeline.aretrieve(retrieval_query)
+    info(f"[RAG Core] pipeline.aretrieve 返回，得到 {len(documents)} 个文档")
+    info(f"[RAG Core] 调用 pipeline.format_context")
     rag_context = pipeline.format_context(documents)
+    info(f"[RAG Core] pipeline.format_context 返回")
 
     info(f"[RAG Core] 获取到 rag_context: {type(rag_context)}, 长度={len(rag_context) if rag_context else 0}")
     info(f"[RAG Core] 获取到 rag_docs: {len(documents)} 个文档")
@@ -69,15 +74,17 @@ async def _rag_retrieve_core(state: MainGraphState, pipeline) -> MainGraphState:
     state.rag_attempts = getattr(state, 'rag_attempts', 0) + 1
     # 移除对 debug_info 的依赖，不再保存 rag_scores
 
+    info(f"[RAG Core] _rag_retrieve_core 结束")
     return state
 
 
 # ========== RAG 检索节点 ==========
 async def rag_retrieve_node(state: MainGraphState, config: Optional[RunnableConfig] = None) -> MainGraphState:
-    """RAG 检索节点：检索 + 置信度评估"""
+    info(f"[RAG] rag_retrieve_node 开始")
     state.current_phase = "rag_retrieving"
     start_time = time.time()
 
+    info(f"[RAG] 调用 _get_rag_pipeline")
     pipeline = _get_rag_pipeline()
 
     await dispatch_custom_event(
@@ -87,9 +94,12 @@ async def rag_retrieve_node(state: MainGraphState, config: Optional[RunnableConf
     )
 
     try:
+        info(f"[RAG] 调用 _rag_retrieve_core")
         state = await _rag_retrieve_core(state, pipeline)
+        info(f"[RAG] _rag_retrieve_core 返回")
 
         # 评估置信度
+        info(f"[RAG] 调用 _evaluate_rag_confidence")
         confidence = await _evaluate_rag_confidence(state)
         state.rag_confidence = confidence
 
@@ -111,10 +121,11 @@ async def rag_retrieve_node(state: MainGraphState, config: Optional[RunnableConf
         )
 
     except Exception as e:
-        info(f"[RAG] 检索失败: {e}")
+        info(f"[RAG] 检索失败: {e}", exc_info=True)
         state.rag_confidence = 0.0
         state.rag_retrieved = False
 
+    info(f"[RAG] rag_retrieve_node 结束")
     return state
 
 

backend/app/rag/fusion.py

@@ -1,8 +1,11 @@
 # rag/fusion.py
 
+import logging
 from typing import List, Dict
 from langchain_core.documents import Document
 
+logger = logging.getLogger(__name__)
+
 def reciprocal_rank_fusion(
     doc_lists: List[List[Document]],
     k: int = 60
@@ -17,12 +20,14 @@ def reciprocal_rank_fusion(
     Returns:
         融合后按 RRF 得分降序排列的文档列表
     """
+    logger.info(f"[RRF] reciprocal_rank_fusion 开始: {len(doc_lists)} 组文档")
     # 使用文档内容作为唯一标识（如果内容相同但 metadata 不同，视为同一文档）
     # 更好的做法是用 docstore 的 ID，这里简化处理：用内容 hash
     doc_to_score: Dict[str, float] = {}
     doc_map: Dict[str, Document] = {}
     
-    for docs in doc_lists:
+    for list_idx, docs in enumerate(doc_lists):
+        logger.info(f"[RRF] 处理第 {list_idx} 组: {len(docs)} 个文档")
         for rank, doc in enumerate(docs, start=1):
             # 生成唯一标识符（内容+来源组合，避免不同文件相同内容混淆）
             doc_id = f"{doc.page_content[:200]}_{doc.metadata.get('source', '')}"
@@ -31,6 +36,9 @@ def reciprocal_rank_fusion(
             score = doc_to_score.get(doc_id, 0.0) + 1.0 / (k + rank)
             doc_to_score[doc_id] = score
     
+    logger.info(f"[RRF] 去重后共 {len(doc_map)} 个唯一文档")
     # 按得分排序
     sorted_ids = sorted(doc_to_score.keys(), key=lambda x: doc_to_score[x], reverse=True)
-    return [doc_map[doc_id] for doc_id in sorted_ids]
+    result = [doc_map[doc_id] for doc_id in sorted_ids]
+    logger.info(f"[RRF] reciprocal_rank_fusion 结束: 返回 {len(result)} 个文档")
+    return result

backend/app/rag/pipeline.py

@@ -62,31 +62,40 @@ class RAGPipeline:
         return self._last_scores
 
     async def aretrieve(self, query: str) -> List[Document]:
+        logger.info(f"[Pipeline] aretrieve 开始: query={query[:50]}...")
         # Step 1: 检索
+        logger.info(f"[Pipeline] Step 1: 调用 _retrieve")
         child_docs = await self._retrieve(query)
-        logger.info(f"[Pipeline] 检索到 {len(child_docs)} 个子文档")
+        logger.info(f"[Pipeline] Step 1 完成: 检索到 {len(child_docs)} 个子文档")
         # 调试：打印子文档长度
         for i, doc in enumerate(child_docs[:5]):
             content_len = len(doc.page_content)
             logger.info(f"[Pipeline]   子文档[{i}] 长度={content_len}字符")
 
         # Step 2: 重排
+        logger.info(f"[Pipeline] Step 2: 开始重排")
         if self.reranker:
             try:
                 child_docs = self.reranker.compress_documents(child_docs, query, self.rerank_top_n)
-                logger.info(f"[Pipeline] 重排后 {len(child_docs)} 个")
+                logger.info(f"[Pipeline] Step 2 完成: 重排后 {len(child_docs)} 个")
             except Exception as e:
                 logger.warning(f"[Pipeline] 重排失败: {e}")
                 child_docs = child_docs[:self.rerank_top_n]
+        else:
+            logger.info(f"[Pipeline] Step 2 跳过: 未启用 reranker")
 
         # Step 3: 获取父文档
+        logger.info(f"[Pipeline] Step 3: 开始获取父文档")
         if self.return_parent_docs:
             parent_docs = await self._get_parents(child_docs)
+            logger.info(f"[Pipeline] Step 3 完成: 获取到 {len(parent_docs)} 个父文档")
             # 保存分数信息到 last_scores 供外部访问
             self._last_scores = self._extract_scores(parent_docs)
+            logger.info(f"[Pipeline] aretrieve 结束: 返回父文档")
             return parent_docs
 
         self._last_scores = self._extract_scores(child_docs)
+        logger.info(f"[Pipeline] aretrieve 结束: 返回子文档")
         return child_docs
 
     def _extract_scores(self, docs: List[Document]) -> List[dict]:
@@ -100,14 +109,27 @@ class RAGPipeline:
         return scores
 
     async def _retrieve(self, query: str) -> List[Document]:
+        logger.info(f"[Pipeline] _retrieve 开始: query={query[:50]}...")
         if self.query_generator:
+            logger.info(f"[Pipeline] _retrieve: 调用 query_generator.agenerate")
             queries = await self.query_generator.agenerate(query)
             queries = [query] + [q for q in queries if q != query]
+            logger.info(f"[Pipeline] _retrieve: 生成 {len(queries)} 个查询: {queries}")
+            logger.info(f"[Pipeline] _retrieve: 开始 asyncio.gather 并行检索")
             doc_lists = await asyncio.gather(*[self.retriever.ainvoke(q) for q in queries])
-            return reciprocal_rank_fusion(doc_lists)
-        return await self.retriever.ainvoke(query)
+            logger.info(f"[Pipeline] _retrieve: asyncio.gather 完成，得到 {len(doc_lists)} 组结果")
+            logger.info(f"[Pipeline] _retrieve: 开始 reciprocal_rank_fusion")
+            result = reciprocal_rank_fusion(doc_lists)
+            logger.info(f"[Pipeline] _retrieve: RRF 完成，得到 {len(result)} 个文档")
+            logger.info(f"[Pipeline] _retrieve 结束")
+            return result
+        logger.info(f"[Pipeline] _retrieve: query_generator 未启用，直接单次检索")
+        result = await self.retriever.ainvoke(query)
+        logger.info(f"[Pipeline] _retrieve 结束")
+        return result
 
     async def _get_parents(self, child_docs: List[Document]) -> List[Document]:
+        logger.info(f"[Pipeline] _get_parents 开始: {len(child_docs)} 个子文档")
         # 收集 parent_id 和对应的分数
         parent_map = {}  # parent_id -> (embedding_score, rerank_score)
 
@@ -120,14 +142,18 @@ class RAGPipeline:
                 rerank_score = doc.metadata.get("rerank_score", 0.0)
                 parent_map[pid] = (embedding_score, rerank_score)
 
+        logger.info(f"[Pipeline] _get_parents: 收集到 {len(parent_map)} 个 unique parent_id")
         if not parent_map:
             logger.warning("[Pipeline] 未找到 parent_id，返回子文档")
             return child_docs
 
         try:
+            logger.info(f"[Pipeline] _get_parents: 调用 create_docstore")
             from backend.rag_core import create_docstore
             docstore, _ = create_docstore()
+            logger.info(f"[Pipeline] _get_parents: 调用 docstore.amget")
             parent_docs =await docstore.amget(list(parent_map.keys()))
+            logger.info(f"[Pipeline] _get_parents: docstore.amget 返回 {len(parent_docs)} 个结果")
 
             # 构建结果，保持分数信息
             result = []
@@ -142,20 +168,25 @@ class RAGPipeline:
 
             result.sort(key=lambda x: x[1], reverse=True)
             docs = [d for d, _ in result]
-            logger.info(f"[Pipeline] 获取到 {len(docs)} 个父文档")
+            logger.info(f"[Pipeline] _get_parents: 最终得到 {len(docs)} 个父文档")
+            logger.info(f"[Pipeline] _get_parents 结束")
             return docs
         except Exception as e:
-            logger.warning(f"[Pipeline] 获取父文档失败: {e}")
+            logger.warning(f"[Pipeline] 获取父文档失败: {e}", exc_info=True)
             return child_docs
 
     def format_context(self, documents: List[Document]) -> str:
+        logger.info(f"[Pipeline] format_context 开始: {len(documents)} 个文档")
         if not documents:
+            logger.info(f"[Pipeline] format_context: 无文档，返回空字符串")
             return ""
         parts = []
         for i, doc in enumerate(documents, 1):
             source = doc.metadata.get("source", "未知来源")
             parts.append(f"【资料 {i}】来源：{source}\n{doc.page_content}\n---\n")
-        return "\n".join(parts)
+        result = "\n".join(parts)
+        logger.info(f"[Pipeline] format_context 结束: 结果长度={len(result)} 字符")
+        return result
 
 
 def create_rag_pipeline(**kwargs) -> RAGPipeline: