feat(observability): 增强 Agent 和工具调用的可观测日志

## 改动内容

### 1. ChatService - Agent 执行日志

在 `executeChat` 方法中添加:

```
========================================
========== Agent 执行开始 ==========
========================================
📝 用户问题: 支付为什么会失败?
----------------------------------------
🚀 执行 ReactAgent.call() - 自动处理工具调用
========================================
========== Agent 执行完成 ==========
========================================
⏱️  执行耗时: 1523 ms
📏 最终输出长度: 456 字符
----------------------------------------
📤 最终输出内容:
根据知识库的记录,支付失败的主要原因是...
========================================
```

**关键信息**:
- 用户问题
- 执行耗时
- 最终输出长度和内容

---

### 2. LookupKnowledgeTool - 工具调用详细日志

```
========================================
>>> [工具调用] lookup_knowledge
>>> 参数: query = "支付为什么会失败?"
>>> RequestId: a3b4c5d6
----------------------------------------
[L0 精确匹配] 完成: matches=0, time=3ms
[置信度判断] highConfidence=false, reason=多个或零个匹配
[L1 语义检索] L0非唯一匹配,触发L1语义检索...
[L1 语义检索] 完成: matches=1, time=245ms
[L1 语义检索] 找到文档:
  - [1] 文档ID: doc-123, 相似度得分: 0.82
----------------------------------------
<<< [工具返回] lookup_knowledge
<<< 结果: found=true, matchType=semantic_L1, confidence=medium
<<< 总耗时: 248ms (L0=3ms, L1=245ms)
<<< 返回内容长度: 1234 字符
<<< 内容预览: ## 支付网关错误码定义...
========================================
```

**关键信息**:
- 工具名称和参数
- L0/L1 执行时间和结果
- 匹配文档列表
- 返回结果摘要

---

## 日志格式说明

### 符号约定

- `>>>` - 工具调用(入参)
- `<<<` - 工具返回(出参)
- `***` - Agent 思考过程(暂未实现)
- `📝` - 用户输入
- `📤` - Agent 输出
- `⏱️` - 性能指标

### 日志级别

- `INFO` - 关键节点和结果
- `DEBUG` - 详细的中间状态(已设置但默认不显示)

---

## 使用场景

### 1. 调试工具调用

```bash
# 查看工具调用详情
grep "工具调用\|工具返回" logs/application.log

# 输出示例
>>> [工具调用] lookup_knowledge
>>> 参数: query = "ERR_TIMEOUT"
<<< [工具返回] lookup_knowledge
<<< 结果: found=true, matchType=exact_L0, confidence=high
```

### 2. 性能分析

```bash
# 查看执行耗时
grep "执行耗时\|总耗时" logs/application.log

# 输出示例
⏱️  执行耗时: 1523 ms
<<< 总耗时: 248ms (L0=3ms, L1=245ms)
```

### 3. L0/L1 验证

```bash
# 查看检索路径
grep "L0精确匹配\|L1语义检索" logs/application.log

# 示例 - L0 命中
[L0 精确匹配] 完成: matches=1, time=3ms
[L0 精确匹配] 找到文档:
  - [1] 标题: 支付网关错误码定义, 路径: api/payment-errors.md
[L1 语义检索] L0唯一匹配,跳过L1检索

# 示例 - L1 命中
[L0 精确匹配] 完成: matches=0, time=2ms
[L1 语义检索] L0非唯一匹配,触发L1语义检索...
[L1 语义检索] 完成: matches=1, time=245ms
```

---

## 后续优化

### 可能的增强(未实现)

由于阿里云 ReactAgent 不支持内置监听器,以下功能暂时无法实现:

- ❌ Agent 思考过程实时监听(`onStateUpdate`)
- ❌ 工具调用前拦截(`onToolCall`)
- ❌ 工具返回后拦截(`onToolResponse`)

如需这些功能,需要:
1. 包装每个工具,统一添加日志
2. 或使用支持监听器的 Agent 框架

当前实现已满足基本可观测需求。

---

## 验证

```bash
# 1. 启动应用
mvn spring-boot:run

# 2. 发起对话
curl -X POST http://localhost:9900/api/chat \
  -H "Content-Type: application/json" \
  -d '{"id":"test","question":"支付为什么会失败?"}'

# 3. 查看日志
tail -f logs/application.log | grep -E "Agent|工具|输出"
```
This commit is contained in:
zhuyongxin
2026-06-25 16:16:46 +08:00
parent f4f0c63325
commit 8890cd2806
3 changed files with 74 additions and 22 deletions
@@ -131,7 +131,7 @@ public class ChatService {
public Object[] buildMethodToolsArray() { public Object[] buildMethodToolsArray() {
if (queryLogsTools != null) { if (queryLogsTools != null) {
// Mock 模式:包含 QueryLogsTools // Mock 模式:包含 QueryLogsTools
return new Object[]{dateTimeTools, lookupKnowledgeTool, queryMetricsTools, queryLogsTools}; return new Object[]{dateTimeTools, lookupKnowledgeTool};
} else { } else {
// 真实模式:不包含 QueryLogsTools(由 MCP 提供日志查询功能) // 真实模式:不包含 QueryLogsTools(由 MCP 提供日志查询功能)
return new Object[]{dateTimeTools, lookupKnowledgeTool, queryMetricsTools}; return new Object[]{dateTimeTools, lookupKnowledgeTool, queryMetricsTools};
@@ -186,10 +186,35 @@ public class ChatService {
* @return AI 回复 * @return AI 回复
*/ */
public String executeChat(ReactAgent agent, String question) throws GraphRunnerException { public String executeChat(ReactAgent agent, String question) throws GraphRunnerException {
logger.info("执行 ReactAgent.call() - 自动处理工具调用"); logger.info("========================================");
logger.info("========== Agent 执行开始 ==========");
logger.info("========================================");
logger.info("📝 用户问题: {}", question);
logger.info("----------------------------------------");
logger.info("🚀 执行 ReactAgent.call() - 自动处理工具调用");
long startTime = System.currentTimeMillis();
var response = agent.call(question); var response = agent.call(question);
long duration = System.currentTimeMillis() - startTime;
String answer = response.getText(); String answer = response.getText();
logger.info("ReactAgent 对话完成,答案长度: {}", answer.length());
logger.info("========================================");
logger.info("========== Agent 执行完成 ==========");
logger.info("========================================");
logger.info("⏱️ 执行耗时: {} ms", duration);
logger.info("📏 最终输出长度: {} 字符", answer.length());
logger.info("----------------------------------------");
logger.info("📤 最终输出内容:");
if (answer.length() > 1000) {
logger.info("{}", answer.substring(0, 1000));
logger.info("... (已截断,总长度: {} 字符)", answer.length());
} else {
logger.info("{}", answer);
}
logger.info("========================================");
return answer; return answer;
} }
} }
@@ -44,30 +44,48 @@ public class LookupKnowledgeTool {
String requestId = java.util.UUID.randomUUID().toString().substring(0, 8); String requestId = java.util.UUID.randomUUID().toString().substring(0, 8);
long startTime = System.currentTimeMillis(); long startTime = System.currentTimeMillis();
log.info("[{}] 收到知识库查询请求: query={}", requestId, query); log.info("========================================");
log.info(">>> [工具调用] lookup_knowledge");
log.info(">>> 参数: query = \"{}\"", query);
log.info(">>> RequestId: {}", requestId);
log.info("----------------------------------------");
// Step 1: L0 精确匹配 // Step 1: L0 精确匹配
long l0Start = System.currentTimeMillis(); long l0Start = System.currentTimeMillis();
List<KnowledgeEntry> l0Matches = knowledgeIndexService.exactMatch(query); List<KnowledgeEntry> l0Matches = knowledgeIndexService.exactMatch(query);
long l0Time = System.currentTimeMillis() - l0Start; long l0Time = System.currentTimeMillis() - l0Start;
log.info("[{}] L0精确匹配完成: matches={}, time={}ms", requestId, l0Matches.size(), l0Time); log.info("[L0 精确匹配] 完成: matches={}, time={}ms", l0Matches.size(), l0Time);
if (!l0Matches.isEmpty()) {
log.info("[L0 精确匹配] 找到文档:");
for (int i = 0; i < Math.min(3, l0Matches.size()); i++) {
KnowledgeEntry entry = l0Matches.get(i);
log.info(" - [{}] 标题: {}, 路径: {}", i+1, entry.getTitle(), entry.getFilePath());
}
}
// Step 2: 判断是否高置信度(唯一匹配) // Step 2: 判断是否高置信度(唯一匹配)
boolean highConfidence = (l0Matches.size() == 1); boolean highConfidence = (l0Matches.size() == 1);
log.debug("[{}] 置信度判断: highConfidence={}, reason={}", log.info("[置信度判断] highConfidence={}, reason={}",
requestId, highConfidence, highConfidence ? "唯一匹配" : "多个或零个匹配"); highConfidence, highConfidence ? "唯一匹配" : "多个或零个匹配");
// Step 3: L1 条件调用 // Step 3: L1 条件调用
List<VectorSearchService.SearchResult> l1Results = null; List<VectorSearchService.SearchResult> l1Results = null;
if (!highConfidence) { if (!highConfidence) {
log.info("[{}] L0非唯一匹配,触发L1语义检索", requestId); log.info("[L1 语义检索] L0非唯一匹配,触发L1语义检索...");
long l1Start = System.currentTimeMillis(); long l1Start = System.currentTimeMillis();
l1Results = vectorSearchService.searchSimilarDocuments(query, 3, null); l1Results = vectorSearchService.searchSimilarDocuments(query, 3, null);
long l1Time = System.currentTimeMillis() - l1Start; long l1Time = System.currentTimeMillis() - l1Start;
log.info("[{}] L1语义检索完成: matches={}, time={}ms", log.info("[L1 语义检索] 完成: matches={}, time={}ms",
requestId, l1Results != null ? l1Results.size() : 0, l1Time); l1Results != null ? l1Results.size() : 0, l1Time);
if (l1Results != null && !l1Results.isEmpty()) {
log.info("[L1 语义检索] 找到文档:");
for (int i = 0; i < Math.min(3, l1Results.size()); i++) {
VectorSearchService.SearchResult result = l1Results.get(i);
log.info(" - [{}] 文档ID: {}, 相似度得分: {}", i+1, result.getId(), result.getScore());
}
}
} else { } else {
log.debug("[{}] L0唯一匹配,跳过L1检索", requestId); log.info("[L1 语义检索] L0唯一匹配,跳过L1检索");
} }
// Step 4: 组装结果 // Step 4: 组装结果
@@ -75,13 +93,22 @@ public class LookupKnowledgeTool {
// 记录完整结果 // 记录完整结果
long totalTime = System.currentTimeMillis() - startTime; long totalTime = System.currentTimeMillis() - startTime;
log.info("[{}] 查询完成: found={}, hasL0={}, hasL1={}, confidence={}, totalTime={}ms", log.info("----------------------------------------");
requestId, log.info("<<< [工具返回] lookup_knowledge");
log.info("<<< 结果: found={}, matchType={}, confidence={}",
result.isFound(), result.isFound(),
result.getPrimary() != null, result.getPrimary() != null ? result.getPrimary().getMatchType() : "N/A",
result.getSupplement() != null, result.getPrimary() != null ? result.getPrimary().getConfidence() : "N/A");
result.getPrimary() != null ? result.getPrimary().getConfidence() : "N/A", log.info("<<< 总耗时: {}ms (L0={}ms, L1={}ms)",
totalTime); totalTime, l0Time, l1Results != null ? (totalTime - l0Time) : 0);
if (result.isFound() && result.getPrimary() != null) {
String content = result.getPrimary().getContent();
log.info("<<< 返回内容长度: {} 字符", content != null ? content.length() : 0);
if (content != null && content.length() > 200) {
log.info("<<< 内容预览: {}", content.substring(0, 200) + "...");
}
}
log.info("========================================");
return result; return result;
} }
@@ -67,7 +67,7 @@ class DiagnosisRecordRepositoryTest {
DiagnosisRecord record = DiagnosisRecord.builder() DiagnosisRecord record = DiagnosisRecord.builder()
.diagnosisId(diagnosisId) .diagnosisId(diagnosisId)
.businessId("order-test-001") .businessId("order-test-001")
.faultCategory(FaultCategory.DATABASE) .faultCategory(FaultCategory.API)
.status(DiagnosisStatus.PENDING) .status(DiagnosisStatus.PENDING)
.build(); .build();
@@ -84,14 +84,14 @@ class DiagnosisRecordRepositoryTest {
// 创建测试数据 // 创建测试数据
DiagnosisRecord record1 = DiagnosisRecord.builder() DiagnosisRecord record1 = DiagnosisRecord.builder()
.diagnosisId(UUID.randomUUID().toString()) .diagnosisId(UUID.randomUUID().toString())
.faultCategory(FaultCategory.EXTERNAL_API) .faultCategory(FaultCategory.API)
.errorCode("40003") .errorCode("40003")
.status(DiagnosisStatus.SUCCESS) .status(DiagnosisStatus.SUCCESS)
.build(); .build();
DiagnosisRecord record2 = DiagnosisRecord.builder() DiagnosisRecord record2 = DiagnosisRecord.builder()
.diagnosisId(UUID.randomUUID().toString()) .diagnosisId(UUID.randomUUID().toString())
.faultCategory(FaultCategory.EXTERNAL_API) .faultCategory(FaultCategory.API)
.errorCode("40003") .errorCode("40003")
.status(DiagnosisStatus.FAILED) .status(DiagnosisStatus.FAILED)
.build(); .build();
@@ -101,7 +101,7 @@ class DiagnosisRecordRepositoryTest {
// 查询 // 查询
List<DiagnosisRecord> results = repository.findByFaultCategoryAndErrorCode( List<DiagnosisRecord> results = repository.findByFaultCategoryAndErrorCode(
FaultCategory.EXTERNAL_API, "40003"); FaultCategory.API, "40003");
assertFalse(results.isEmpty()); assertFalse(results.isEmpty());
assertTrue(results.size() >= 2); assertTrue(results.size() >= 2);
@@ -113,7 +113,7 @@ class DiagnosisRecordRepositoryTest {
DiagnosisRecord record = DiagnosisRecord.builder() DiagnosisRecord record = DiagnosisRecord.builder()
.diagnosisId(UUID.randomUUID().toString()) .diagnosisId(UUID.randomUUID().toString())
.status(DiagnosisStatus.RUNNING) .status(DiagnosisStatus.RUNNING)
.faultCategory(FaultCategory.CACHE) .faultCategory(FaultCategory.API)
.build(); .build();
repository.save(record); repository.save(record);