MAT OQL 排查字符串泄漏:从 4GB Dump 到一行代码的定位过程
当 Dominator Tree 失效时OQL 才是字符串泄漏的真正入口。4GB dump 里 6000 万个 String 的排查实录。14:02告警弹窗Old Gen 82.5%FullGC 32 分钟一次。第一反应——查 Dominator Tree支配树视图。几乎所有 MAT 教程教的第一件事就是它——找出谁 retain 了最多内存然后自顶向下追。但这次 Dominator Tree 给的答案全是char[]没有任何业务对象。六千多万个 String 挂在那里你问它谁 retain 了它们——它说它们自己。排查到这里有鬼——常规路线走不通了。场景故事系统背景订单推送网关JDK 8堆 8GBParNewCMS。近一周 FullGC 从每4小时一次恶化到每30分钟一次。时间线14:02 CMS 告警→14:05 jmap 导出→14:12 MAT OOM→14:18 调参重开→14:30 Histogram 发现 String 异样→14:45 OQL 定位重复 substring→14:50 代码确认冲突堆 8GBdump 4.2GB。MAT 默认 -Xmx1024m 直接撑爆。调大后 Dominator Tree 看到的全是 char[]找不到业务层面的泄漏点转折点切换到 OQLSELECT toString(s) FROM java.lang.String s WHERE s.value.length 200才发现大量重复的 JSON 片段子串。不是字符串太多而是每个字符串都是大字符串的残片技术关键点MAT 参数调优、OQLObject Query Language语法、retained size保留集 vs shallow size浅堆、substring 在 JDK 7 的底层行为变化修复Matcher.group()返回的 String 替换为input.subSequence(start, end)intern()告警截图类型: metric — CMS 老年代增长曲线Old Gen 从 2.1GB 在 6 小时内爬升到 6.8GB告警信号14:02告警弹窗CMS Old Gen 使用率 82.5%FullGC 间隔已缩短至 32 分钟预计 2 小时后触发 Concurrent Mode Failure。这不是偶然的 GC 波动——是堆在持续增长且从来没有降下来过。CMS 的 remark 阶段耗时从 200ms 涨到了 1.8s。线程 Dump 显示大部分线程卡在ReferenceProcessor的引用处理上——典型的字符串引用过多信号。团队群里的反应很一致——要不要先重启这是线上出问题时最常见的对话——重启能止血但不能定位。跳过重启直接分析是因为即使重启了根因没找到半小时后告警还会回来。但重启只能止血不能定位。拿到堆转储才是排查内存泄漏的第一步——没有 dump后面的所有分析都是空谈。从监控上看YoungGC 频率正常每秒约 0.8 次但每次晋升promotion的对象量在增加。说明不是临时对象太多而是有东西留在老年代不走了。这一步排除了GC 参数不合理导致晋升过快的可能——问题出在业务层不是 GC 配置层。起手截图类型: server — jmap 导出命令 MAT MemoryAnalyzer.ini 配置导出堆转储先拿堆——排查内存问题第一步永远是导出堆转储。$ jps-l|grepOrderPushGateway31472cn.opencao.push.OrderPushGateway $ jmap -dump:live,formatb,file/tmp/heap-1430.hprof31472Dumping heap to /tmp/heap-1430.hprof... Heap dumpfilecreated,4.2GBin38seconds用-dump:live而不是-dump:all——先触发一次 FullGC只保留有引用链存活的对象。这一步排除了垃圾对象对分析的干扰让 dump 文件只包含真正泄漏的数据。4.2GB全是活的。MAT 初探HistogramMATEclipse Memory Analyzer Tool默认的-Xmx1024m显然不够打开 4.2GB dump——直接报了 OOM。# MemoryAnalyzer.ini — 调大 MAT 堆-Xmx6g-XX:-UseGCOverheadLimit调大后重开第一个入口——Histogram。按 Retained Heap保留集即该对象它引用的所有后代的总大小排序前两行触目惊心ClassObjectsShallow HeapRetained Heapchar[]8,312,0442.1 GB2.1 GBjava.lang.String6,140,651245.6 MB2.3 GBbyte[]1,203,488348.2 MB348.2 MBjava.util.HashMap$Node1,872,44689.8 MB1.2 GBString char[] 超过 4.5GB堆里 60% 以上是字符串。到这里已经可以确定这是一个字符串泄漏问题。但问题的关键在于谁在引用这些字符串正常思路是切到 Dominator Tree——找出 retain 最多内存的根。但 Dominator Tree 按 retained set 排序String 之间互相引用少每个 String 只 retain 自己的 char[]树顶看到的全是 char[] 实例看不到业务对象。知道字符串多但不知道谁在引用它们——这是第一个岔路。收敛截图类型: diagram — 排查路径决策图OQL 按长度分类Dominator Tree 走不通换个思路——不追对象图拓扑。MAT 的 OQLObject Query Language对象查询语言支持从值语义维度做聚合。也就是说不关心谁引用了谁直接按字符串长度分组统计SELECTs.value.lengthASlen,COUNT(*)AScntFROMjava.lang.String sWHEREs.value!nullGROUPBYlenORDERBYcntDESCLIMIT20结果长度为 248、312、476 的三个区间占了 240 万 String 对象。这不是自然分布。自然分布应该是均匀的长尾而不是三个尖峰。这把字符串多细化成了特定长度的字符串特别多——说明这些字符串来自同一个源头。OQL 按内容抽样既然长度集中看内容SELECTtoString(s)AScontent,s.value.lengthASlenFROMjava.lang.String sWHEREs.value.length248LIMIT10结果令人惊讶——这些 248 字符的 String 全是同一个 JSON 的子串片段status:PROCESSING,orderId:OR2026061400001,timestamp:...每一个都像从一个更大的 JSON 里切出来的子串。既不像正常业务字符串也不像日志——它是substring()的结果。这一步排除了日志框架字符串保留和JSON 序列化缓存的可能——问题锁定在字符串截取上。追溯调用链知道内容长什么样了——接下来回答谁留下了这些字符串。用 OQL 按内容匹配然后追溯 incoming referenceSELECT*FROMjava.lang.String sWHEREtoString(s)LIKE%PROCESSING%ANDs.value.length100在结果集上任选一个 String → 右键 →Calculate Minimum Retained Set计算最小保留集→ 追踪到调用链OrderExportHandler.extractOrderId()→ java.util.regex.Matcher.group()→ String.substring()到这里出现了一个让人停下来的时刻直觉substring() 返回的是小字符串应该很快被 GC怎么进了老年代真相不是一个大字符串在泄漏。是每个请求都会创建新的 substring 对象它们被积累在了一个没有过期策略的 ConcurrentHashMap 里。日积月累数百万个唯一的 orderId String 塞满了老年代。单看一段代码看不出问题——matcher.group(1)太常见了。但 OQL 让这个时间累积效应现了形。用 OQL 而不是 Dominator Tree 的关键原因当几百个 char[] 不知道属于谁时按值聚合比按拓扑追溯更快。定位截图类型: code — 根因代码group()substring() 行高亮根因代码定位到了OrderExportHandler。红色高亮的两行就是元凶①matcher.group(1)做了什么JDK 8 的Matcher.group()内部调用subSequence()最终走的是String.substring()。JDK 7 之后substring()不再共享父字符串的char[]而是每次拷贝一份新的char[]publicStringsubstring(intbeginIndex,intendIndex){intsubLenendIndex-beginIndex;returnnewString(value,beginIndex,subLen);// new char[subLen]}每个group(1)对应一次new char[24]——orderId 虽然短每天百万级请求累积到一定周期就成了问题。②taskCache为什么是永久的代码用ConcurrentHashMap做处理器级缓存但没有 put 上限、没有 TTL、没有 LRU。业务逻辑漏了删除已完成的条目所有历史 orderId 留在了 Map 里。问题不在单个对象——单个 String 不过几十字节。问题在缓存模型选型与业务生命周期不匹配。如果缓存对象数不超过 1 万用ConcurrentHashMap没问题但这个场景下 map 键数会每日增长注定爆炸。复盘截图类型: diff — 修复前后 OQL 查询对比复盘要点整篇排查从告警到定位耗时 48 分钟。以下是完整时间线有鬼时刻复盘为什么 Dominator Tree 不好使Dominator Tree 按 retained heap 排序但 String 的 retained set 几乎只有自己的 char[]——每个 String 浅小但独立树顶被成千上万的 char[] 占据看不出业务聚合。OQL 用的思维不同值语义聚合——不关心谁保留谁关心哪些值重复出现。对字符串泄漏排查来说值语义比对象拓扑更直接。三个止血点按实施难度排序最便宜缓存过期策略——Caffeine/Guava Cache/expireAfterWrite一行配置解决绝大多数缓存泄漏中等Matcher.group()→input.subSequence(start, end)但不适用于需要独立 String 的场景最彻底用CharBuffer/ 偏移量引用替代字符串切分零拷贝OQL 不是替代码审查的工具它是代码审查的放大器。一行group(1)写下去不会想到 6 个月后它在堆里长成 600 万个 String。OQL 能让你看到这个时间累积效应。修复方案修复 1缓存过期策略privatefinalCacheString,ExportTasktaskCacheCaffeine.newBuilder().maximumSize(10_000).expireAfterWrite(30,TimeUnit.MINUTES).build();修复 2用subSequence替代group()CharSequenceorderIdpayload.subSequence(matcher.start(1),matcher.end(1));不产生新 String 对象零拷贝。修复效果指标修复前修复后char[]数量831 万220 万String数量614 万118 万堆中字符串占比60%18%FullGC 间隔32 min6h附完整命令清单# 1. 导出堆jmap -dump:live,formatb,file/tmp/heap.hprofpid# 2. MAT 调参MemoryAnalyzer.ini-Xmx6g-XX:-UseGCOverheadLimit# 3. MAT OQL 查询按长度分布SELECT s.value.length AS len, COUNT(*)AS cnt FROM java.lang.String s GROUP BY len ORDER BY cnt DESC;# 4. MAT OQL 查询查内容SELECT toString(s)FROM java.lang.String s WHERE s.value.length248LIMIT10;# 5. MAT OQL 查询查来源追溯SELECT * FROM java.lang.String s WHERE toString(s)LIKE%PROCESSING%AND s.value.length100;# 6. Maven 依赖Caffeine 缓存# dependency# groupIdcom.github.ben-manes.caffeine/groupId# artifactIdcaffeine/artifactId# version3.1.8/version# /dependency