AI 应用的日志设计——记什么才有分析价值
AI 应用的日志设计——记什么才有分析价值
一个同事来找我,说他们的 AI 问答系统有时候回答质量很差,用户反馈很多,但他完全不知道哪些问题类型最容易失败,失败的时候模型在想什么,Prompt 是否需要调整。
我问他:「你们的日志里记了什么?」
他打开日志文件,我看了一眼:
2024-12-15 14:23:11 INFO Request received: POST /api/chat
2024-12-15 14:23:11 INFO User authenticated: user_123
2024-12-15 14:23:14 INFO Response sent successfully这是日志,但它们没有任何分析价值。
我知道有个请求来了,我知道它成功了,但我不知道:用户问了什么、模型用了哪个版本、消耗了多少 Token、延迟是多少、检索到了哪些文档、模型给了什么答案。我甚至不知道「成功」是不是意味着「正确」。
这篇文章专门讲 AI 应用的日志设计,重点不是「怎么打日志」,而是「记什么才能做事后分析」。
一、AI 日志和普通应用日志的核心差异
普通应用日志的主要用途是排查故障:出错了能找到原因,复现场景。
AI 应用的日志需要多一个用途:效果分析。你需要能从日志里回答这些问题:
- 哪类问题的回答质量最差?
- Prompt 修改之后效果有没有变好?
- 哪些问题触发了降级(切换到备用模型)?
- Token 消耗的分布是什么?有没有异常高消耗的请求类型?
- 用户的 session 里,哪个环节最容易导致对话终止?
这些问题要求日志具备可分析性:字段标准化、维度足够多、可以做聚合和过滤。
随意的文本日志是不够的,需要结构化日志。
二、AI 应用结构化日志字段设计
每条 AI 请求日志应该包含的核心字段:
{
"timestamp": "2024-12-15T14:23:14.521Z",
"level": "INFO",
"logger": "ai.query.service",
// === 请求追踪字段 ===
"request_id": "req_a1b2c3d4",
"trace_id": "trace_x9y8z7",
"session_id": "sess_abc123", // 同一个对话的所有轮次共享同一个 session_id
"user_id": "user_456",
"tenant_id": "tenant_xyz",
// === AI 模型字段 ===
"model": "gpt-4o",
"model_version": "2024-11-20", // 模型的具体版本(API 返回)
"prompt_version": "v1.23.0", // Prompt 配置版本(对应配置中心版本号)
"scene": "customer_service",
// === 性能字段 ===
"ttft_ms": 1234, // 首 Token 时间
"total_latency_ms": 5678,
"retrieval_latency_ms": 234, // RAG 检索耗时
"model_call_latency_ms": 5100, // 模型调用耗时(不含检索)
// === Token 字段 ===
"input_tokens": 1523,
"output_tokens": 387,
"total_tokens": 1910,
// === RAG 字段 ===
"retrieval_count": 5, // 检索到的文档数
"avg_semantic_score": 0.82, // 平均相关性得分
"kb_name": "customer_service_kb",
// === 质量信号字段 ===
"is_stream": true,
"stream_completed": true,
"fallback_triggered": false,
"fallback_layer": null,
"content_filtered": false,
// === 分类字段(用于按问题类型分析)===
"query_intent": "product_inquiry", // AI 分类的意图
"query_category": "shipping", // 问题大类
// === 错误字段 ===
"error": null,
"error_type": null,
// === 内容摘要字段(脱敏后的)===
"query_length": 45, // 用户问题的字符长度(不记录原文)
"answer_length": 312, // 回答长度
"has_user_feedback": false, // 此次是否有用户反馈
// 环境信息
"pod_id": "ai-service-pod-abc",
"app_version": "2.1.3"
}这些字段覆盖了分析所需的基本维度。注意:不要把用户的原始问题和 AI 的原始回答记进日志,隐私合规风险极大。记长度、摘要、分类标签,但不记原文。
三、基于 Logback 的 AI 结构化日志配置
3.1 Logback 配置
<!-- logback-spring.xml -->
<configuration>
<!-- 自定义 JSON 格式的 Appender -->
<appender name="AI_STRUCTURED_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>/var/log/app/ai-structured.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>/var/log/app/ai-structured.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
<encoder class="net.logstash.logback.encoder.LogstashEncoder">
<!-- 使用 logstash-logback-encoder 输出 JSON 格式 -->
<includeCallerData>false</includeCallerData>
<includeMdc>true</includeMdc>
</encoder>
</appender>
<!-- 控制台输出(开发环境友好格式)-->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<!-- AI 结构化日志单独输出到文件 -->
<logger name="ai.structured" level="INFO" additivity="false">
<appender-ref ref="AI_STRUCTURED_LOG"/>
</logger>
<root level="INFO">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>3.2 AI 结构化日志工具类
@Component
@Slf4j
public class AiStructuredLogger {
private static final Logger AI_LOG = LoggerFactory.getLogger("ai.structured");
@Autowired
private ObjectMapper objectMapper;
/**
* 记录一次完整的 AI 请求(请求完成后调用)
*/
public void logAiRequest(AiRequestLog logData) {
try {
// 构建结构化日志的 MDC 字段
MDC.put("request_id", logData.getRequestId());
MDC.put("session_id", logData.getSessionId());
MDC.put("user_id", logData.getUserId());
MDC.put("model", logData.getModel());
MDC.put("scene", logData.getScene());
MDC.put("prompt_version", logData.getPromptVersion());
// 使用 StructuredArguments 记录所有字段
AI_LOG.info("ai_request",
StructuredArguments.entries(toLogMap(logData))
);
} finally {
MDC.remove("request_id");
MDC.remove("session_id");
MDC.remove("user_id");
MDC.remove("model");
MDC.remove("scene");
MDC.remove("prompt_version");
}
}
private Map<String, Object> toLogMap(AiRequestLog data) {
Map<String, Object> map = new LinkedHashMap<>();
map.put("event_type", "ai_request");
map.put("request_id", data.getRequestId());
map.put("session_id", data.getSessionId());
map.put("user_id", maskUserId(data.getUserId()));
map.put("tenant_id", data.getTenantId());
map.put("model", data.getModel());
map.put("model_version", data.getModelVersion());
map.put("prompt_version", data.getPromptVersion());
map.put("scene", data.getScene());
map.put("ttft_ms", data.getTtftMs());
map.put("total_latency_ms", data.getTotalLatencyMs());
map.put("retrieval_latency_ms", data.getRetrievalLatencyMs());
map.put("model_call_latency_ms", data.getModelCallLatencyMs());
map.put("input_tokens", data.getInputTokens());
map.put("output_tokens", data.getOutputTokens());
map.put("retrieval_count", data.getRetrievalCount());
map.put("avg_semantic_score", data.getAvgSemanticScore());
map.put("is_stream", data.isStream());
map.put("stream_completed", data.isStreamCompleted());
map.put("fallback_triggered", data.isFallbackTriggered());
map.put("fallback_layer", data.getFallbackLayer());
map.put("content_filtered", data.isContentFiltered());
map.put("query_intent", data.getQueryIntent());
map.put("query_category", data.getQueryCategory());
map.put("query_length", data.getQueryLength());
map.put("answer_length", data.getAnswerLength());
map.put("error", data.getError());
map.put("error_type", data.getErrorType());
map.put("pod_id", System.getenv("POD_NAME"));
return map;
}
private String maskUserId(String userId) {
if (userId == null || userId.length() <= 4) return "****";
return userId.substring(0, 2) + "****" + userId.substring(userId.length() - 2);
}
}3.3 AiRequestLog 数据模型
@Data
@Builder
public class AiRequestLog {
// 追踪字段
private String requestId;
private String sessionId;
private String userId;
private String tenantId;
// 模型字段
private String model;
private String modelVersion;
private String promptVersion;
private String scene;
// 性能字段
private Long ttftMs;
private Long totalLatencyMs;
private Long retrievalLatencyMs;
private Long modelCallLatencyMs;
// Token 字段
private Integer inputTokens;
private Integer outputTokens;
// RAG 字段
private Integer retrievalCount;
private Double avgSemanticScore;
private String kbName;
// 质量信号
private boolean stream;
private boolean streamCompleted;
private boolean fallbackTriggered;
private String fallbackLayer;
private boolean contentFiltered;
// 分类字段
private String queryIntent;
private String queryCategory;
// 内容摘要(不记录原文)
private Integer queryLength;
private Integer answerLength;
// 错误字段
private String error;
private String errorType;
}3.4 在 AOP 切面中自动记录
@Aspect
@Component
@Slf4j
public class AiLoggingAspect {
@Autowired
private AiStructuredLogger aiLogger;
@Autowired
private QueryClassifier queryClassifier; // 用于意图识别
@Around("@annotation(aiTracked)")
public Object logAiCall(ProceedingJoinPoint pjp, AiTracked aiTracked) throws Throwable {
long startTime = System.currentTimeMillis();
String requestId = UUID.randomUUID().toString();
String sessionId = SessionContext.getCurrentSessionId();
AiRequestLog.AiRequestLogBuilder logBuilder = AiRequestLog.builder()
.requestId(requestId)
.sessionId(sessionId)
.userId(SecurityContext.getCurrentUserId())
.model(aiTracked.model())
.scene(aiTracked.scene());
Object firstArg = pjp.getArgs().length > 0 ? pjp.getArgs()[0] : null;
// 记录查询信息(不记原文,只记长度和分类)
if (firstArg instanceof String query) {
logBuilder.queryLength(query.length());
// 异步做意图分类(不阻塞主流程)
CompletableFuture.runAsync(() -> {
try {
QueryClassification cls = queryClassifier.classify(query);
// 这里只能影响后续请求的日志,当前请求的分类是事后追加的
log.debug("Query classified: intent={}, category={}", cls.getIntent(), cls.getCategory());
} catch (Exception e) {
log.warn("Query classification failed", e);
}
});
}
try {
Object result = pjp.proceed();
long totalLatency = System.currentTimeMillis() - startTime;
if (result instanceof AiResponse response) {
logBuilder
.totalLatencyMs(totalLatency)
.inputTokens(response.getInputTokens())
.outputTokens(response.getOutputTokens())
.answerLength(response.getContent() != null ? response.getContent().length() : 0)
.streamCompleted(true)
.fallbackTriggered(response.getModelLayer() != ModelLayer.PRIMARY)
.fallbackLayer(response.getModelLayer() != null ? response.getModelLayer().name() : null);
}
aiLogger.logAiRequest(logBuilder.build());
return result;
} catch (Exception e) {
long totalLatency = System.currentTimeMillis() - startTime;
logBuilder
.totalLatencyMs(totalLatency)
.error(e.getClass().getSimpleName())
.errorType(classifyError(e));
aiLogger.logAiRequest(logBuilder.build());
throw e;
}
}
private String classifyError(Exception e) {
if (e instanceof TimeoutException) return "timeout";
if (e.getMessage() != null && e.getMessage().contains("429")) return "rate_limited";
if (e.getMessage() != null && e.getMessage().contains("token")) return "token_exceeded";
return "unknown";
}
}四、从日志里做 Prompt 效果分析
有了结构化日志,下面是几个实际的分析场景。
4.1 找出最常失败的 Query 类型
用 SQL(如果日志导入了 ClickHouse 或 ElasticSearch):
-- 按问题类型分析错误率
SELECT
query_category,
query_intent,
COUNT(*) AS total_requests,
SUM(CASE WHEN error IS NOT NULL THEN 1 ELSE 0 END) AS error_count,
ROUND(SUM(CASE WHEN error IS NOT NULL THEN 1 ELSE 0 END) * 100.0 / COUNT(*), 2) AS error_rate_pct,
ROUND(AVG(total_latency_ms), 0) AS avg_latency_ms,
ROUND(AVG(avg_semantic_score), 3) AS avg_semantic_score
FROM ai_request_logs
WHERE timestamp >= NOW() - INTERVAL 7 DAY
AND scene = 'customer_service'
GROUP BY query_category, query_intent
ORDER BY error_rate_pct DESC
LIMIT 20;这个查询会告诉你:哪类问题错误率最高、哪类问题延迟最大、哪类问题的语义相关性最低。
4.2 分析 Prompt 版本更新效果
-- 对比 Prompt 版本更新前后的关键指标
SELECT
prompt_version,
COUNT(*) AS requests,
ROUND(AVG(total_latency_ms), 0) AS avg_latency_ms,
ROUND(AVG(input_tokens + output_tokens), 0) AS avg_tokens,
ROUND(AVG(avg_semantic_score), 3) AS avg_semantic_score,
ROUND(SUM(CASE WHEN fallback_triggered THEN 1 ELSE 0 END) * 100.0 / COUNT(*), 2) AS fallback_rate_pct
FROM ai_request_logs
WHERE timestamp >= '2024-12-01'
AND scene = 'customer_service'
GROUP BY prompt_version
ORDER BY MIN(timestamp);这个查询可以清晰地看出每次 Prompt 版本更新后,各项指标有没有改善。
4.3 识别 Token 消耗异常的场景
-- 找出 Token 消耗最高的 10% 请求
SELECT
request_id,
scene,
query_intent,
input_tokens,
output_tokens,
input_tokens + output_tokens AS total_tokens,
query_length,
retrieval_count
FROM ai_request_logs
WHERE timestamp >= NOW() - INTERVAL 1 DAY
AND total_latency_ms IS NOT NULL
ORDER BY (input_tokens + output_tokens) DESC
LIMIT 100;高 Token 消耗的请求往往暴露了 Prompt 设计问题(太多冗余说明)或 RAG 检索问题(召回了太多文档)。
4.4 Session 级别的分析
-- 分析单个 Session 的对话轨迹(排查特定用户反馈问题)
SELECT
session_id,
timestamp,
scene,
query_intent,
total_latency_ms,
input_tokens + output_tokens AS tokens,
fallback_triggered,
error
FROM ai_request_logs
WHERE session_id = 'sess_abc123'
ORDER BY timestamp;这个查询可以复现一个具体用户的完整对话过程,是排查「用户说回答不对」类投诉的最有效工具。
五、日志收集链路
日志从应用产生到可以查询,需要一个收集链路。推荐架构:
应用(Logback JSON)
→ Filebeat(采集文件日志)
→ Kafka(缓冲,防止突发流量)
→ Logstash(清洗和路由)
→ Elasticsearch(存储和索引)
→ Kibana / Grafana(查询和可视化)AI 结构化日志和普通应用日志建议分开索引,因为 AI 日志有大量数值字段需要做聚合计算,而普通日志主要做全文检索,查询模式差异大。
六、日志的隐私合规
一个必须单独说的话题。
AI 应用涉及用户输入的文本,这些文本可能包含个人信息、商业机密、敏感话题。原始用户问题和 AI 回答一定不要记进日志,这是一个隐私合规的红线。
正确做法:
- 记长度不记内容:
query_length: 45而不是query: "我的订单号是..." - 记分类不记细节:
query_intent: "order_inquiry"而不是原始文本 - 如果确实需要记录内容做调试,使用专门的调试日志,有独立的权限控制和更短的保留期
对用户 ID 做脱敏处理,不要在日志里出现明文用户 ID(除非在严格权限控制的内部系统里)。
总结
AI 应用的结构化日志设计的核心是「为分析而设计,不只是为排障而设计」。
关键字段分五类:追踪字段(request_id、session_id)、模型字段(model、prompt_version)、性能字段(ttft、latency)、质量字段(semantic_score、fallback)、分类字段(query_intent、query_category)。
有了这些字段,你才能做到:
- 定量分析 Prompt 版本更新的效果
- 精确定位哪类问题失败率最高
- 追溯任意一个用户投诉的完整上下文
日志不记或记得乱,出了问题只能靠猜。
