生产性能优化——用 AI 分析 GC 日志和慢查询
生产性能优化——用 AI 分析 GC 日志和慢查询
适读人群：有生产性能排查经验的 Java 开发者 | 阅读时长：约 14 分钟 | 核心价值：掌握用 AI 辅助分析 GC 日志和慢查询的实战方法，以及 AI 分析结论的可信度判断
去年 11 月，我们有个服务在促销活动期间响应时间从正常的 80ms 飙到了 2000ms+，偶尔还有超时。
当时我同时开着三个窗口：Grafana 看监控、SSH 连着服务器看日志、还有一个 ChatGPT 的对话窗口。
同事问我："你在跟 AI 聊什么？"
我说："让它帮我分析 GC 日志。"
他的表情很微妙——半信半疑那种。
结果是：AI 的分析帮我定位了问题，节省了大概 2 个小时。但它也给了我两个完全错误的方向，差点让我走弯路。
这篇文章就写这次排查的全过程，AI 对了哪些，错了哪些，以及我总结出来的使用方式。
案例背景
服务是一个商品详情服务，Java 17，JVM 堆 4GB，G1GC。问题症状：
- 响应时间 P99 从 80ms 升到 2000ms
- CPU 使用率正常，在 40% 左右
- 服务没有 OOM，也没有明显的错误日志
- 问题在流量高峰时出现，流量下去之后会缓解
第一步是收集 GC 日志。我在 JVM 启动参数里加了：
-Xlog:gc*:file=/logs/gc.log:time,uptime,level,tags:filecount=5,filesize=20m拿到日志之后，我截取了大约 500 行（问题期间的），扔给了 AI。
AI 分析 GC 日志——对的部分
我给 AI 的 prompt 是：
以下是 Java 17 G1GC 的 GC 日志，服务在这段时间响应时间异常高。
请帮我分析：
1. GC 频率是否异常
2. 停顿时间是否过长
3. 堆内存使用模式是否有问题
4. 可能的根因
[日志内容]AI 的分析里，这几点是准确的：
准确点 1：识别出 Full GC 的频率
AI 说："日志显示在 14:23 到 14:31 的 8 分钟内，发生了 3 次 Full GC，平均每 2.5 分钟一次。正常情况下 G1GC 的 Full GC 应该极少发生，如此频率说明存在严重的内存压力。"
这个判断是对的。G1GC 的 Full GC 是 stop-the-world 的，3次/8分钟这个频率确实很不正常。
准确点 2：识别出停顿时间分布
AI 从日志里提取出了停顿时间数据，发现 Minor GC 的停顿时间从平均 15ms 突然跳到了 180ms，并且指出："这种突变通常不是 GC 调优参数的问题，更可能是对象分配速率突然增大或者存在大对象分配。"
这个分析很有价值。我后来确认，确实存在大对象问题。
准确点 3：提出查 Humongous Allocation
AI 在日志里找到了一些 Humongous Allocation 的记录（大于 Region 大小 50% 的对象分配），建议我重点排查这些大对象是谁在分配。这个方向直接指向了最终的问题根因。
AI 分析 GC 日志——错的部分
错误点 1：错误的 JVM 参数建议
AI 建议我增加 -XX:G1HeapRegionSize=32m，理由是"可以减少 Humongous Allocation 的频率"。
这个建议本身逻辑是通的——增大 Region Size 确实能让更多对象不被认为是"大对象"。但问题是，它没有考虑我的堆大小是 4GB。把 Region Size 设为 32MB 意味着只有 128 个 Region，这会降低 G1GC 的并发回收效率。正确的做法是先搞清楚大对象是什么，而不是调参数把症状掩盖掉。
错误点 2：把内存泄漏当成了根因
AI 在分析堆使用模式时，看到堆在高峰期逐渐增长，就判断"存在内存泄漏的可能"。
但这个增长完全是正常的流量增长导致的。AI 把"流量增加 → 对象增多 → 堆使用增加"这个正常现象误判为内存泄漏。我花了 30 分钟跑 heap dump 分析，证明不是泄漏，这 30 分钟是被 AI 带偏的。
把慢查询日志喂给 AI
GC 日志只是一个线索。我同时把 MySQL 的 slow query log 也拿出来分析。
慢查询日志的格式本身就很结构化，AI 在处理这类数据时效果更好。我给了 AI 大约 50 条慢查询记录，让它：
- 按照查询类型分类汇总
- 找出出现频率最高的慢查询
- 分析可能的优化方向
这部分 AI 的表现更靠谱。它识别出了两类高频慢查询：
-- 类型 1：缺少索引的范围查询
SELECT * FROM product_detail
WHERE category_id = ? AND status = 1 AND created_at > ?
-- AI 指出：created_at 字段缺少索引，全表扫描
-- 类型 2：SELECT *
SELECT * FROM product_sku WHERE product_id = ?
-- AI 指出：返回了 23 列，但调用方只用了 3 列，建议指定列名AI 还发现了一个我自己没注意到的问题：同一个 SQL 在日志里出现了两种执行计划（通过查询时间的分布可以推断），建议检查是否存在索引失效的情况。
这个观察是对的。查下去发现，status 字段由于数据分布不均匀（99% 的数据 status=1），MySQL 有时候会放弃走组合索引，改用全表扫描。
处理火焰图
我们还生成了 async-profiler 的火焰图，保存为 SVG。AI 无法直接读取图像，所以我用了一个变通方案：
# 用 async-profiler 生成 collapsed 格式的 profiling 数据
./profiler.sh -d 30 -f /tmp/profile.collapsed <pid>然后用脚本把 top 50 的热点方法提取出来，以文本形式给 AI 分析：
热点方法 Top 20 (按 CPU 时间占比):
1. 18.3% - com.mysql.cj.jdbc.ConnectionImpl.execSQL()
2. 12.1% - com.fasterxml.jackson.databind.ObjectMapper.writeValueAsString()
3. 8.7% - java.lang.String.getBytes()
4. 7.2% - com.example.service.ProductDetailService.buildDetailVO()
5. 6.1% - redis.clients.jedis.Jedis.get()
...AI 的分析：
"从热点分布来看，MySQL 操作占 18%，这与慢查询问题吻合。但 Jackson 序列化占 12% 值得关注——正常情况下序列化不应该是主要瓶颈。建议检查是否存在过深的对象嵌套、循环引用，或者频繁序列化大对象。另外 String.getBytes() 占 8.7% 且排名靠前，可能与日志或序列化相关，需要确认字符集转换是否必要。"
这个分析是有参考价值的。后来查下去，发现 buildDetailVO() 里确实存在一个问题：它把商品的完整描述 HTML（平均 50KB）每次都序列化进 Redis 缓存，而实际上列表页只需要前 100 个字符的摘要。
综合评估：AI 在性能分析里的实际价值
经过这次和后续的几次实践，我对 AI 做性能分析的价值有了比较清晰的认知：
AI 擅长的（可以高度依赖）：
- 从大量结构化日志里提取模式和统计信息
- 识别明显的反模式（缺索引、SELECT *、N+1 查询）
- 把你提供的多个证据（GC 日志 + 慢查询 + 热点方法）做关联分析，给出综合判断
AI 一般的（参考就行，要验证）：
- 识别 GC 停顿时间是否异常（需要结合业务场景）
- 判断内存使用模式是否正常（容易被正常的流量波动干扰）
AI 容易出错的（谨慎采纳）：
- 给出具体的 JVM 调优参数（缺乏对你系统全局的了解）
- 判断是否是内存泄漏（需要更多工具支持，文本日志信息不够）
- 在日志数据不完整时给出的原因推断（它会编出听起来合理但不对的结论）
我现在的使用方式：
把 AI 当一个"有经验但不了解你系统的顾问"。它能帮你快速梳理证据、提出假设，但每一个假设都需要你自己去验证。不要让它直接给你解决方案，而是让它帮你生成"下一步应该验证什么"的检查清单。
那次排查最终结论：Humongous Allocation 的根因是 buildDetailVO() 每次构造了一个大的包含完整 HTML 的对象，在高并发下这些大对象频繁分配和回收触发了 Full GC。优化方案是把大字段从 VO 里拆出去，按需加载。上线后 Full GC 消失，响应时间回到了 90ms 以内。
整个排查过程 AI 帮我省了 2 个小时，但也让我走了 30 分钟的弯路。净收益是正的，但要带着批判性思维用它。