1. 事故现象与初步判断
先说说我遇到的一个真实案例。某个线上Java服务,平时运行得挺稳,某天下午突然收到监控告警,接口耗时从平均80毫秒直接飙到3秒以上,紧接着一堆调用方开始超时重试,重试又把服务打得更满,页面上的错误率眼看着往上蹿。我第一反应是“是不是数据库慢查询拖垮了服务”,结果上去一看数据库负载正常,网络也正常,反而是服务所在机器的CPU使用率达到了800%(8核机器),而且堆内存使用曲线像过山车一样,一会儿冲到90%一会儿又跌回30%。
这种情况下,十有八九是GC出了问题。Java程序跑在JVM里,JVM自动帮我们管理内存,但一旦垃圾回收跟不上对象分配的速度,或者回收本身消耗了大量CPU,就会出现“服务没死但比死还难受”的状态。所谓的GC问题,本质上是两个矛盾:一是内存分配速度远大于回收速度,二是回收器频繁执行Full GC导致线程停顿(Stop The World,简称STW),结果就是接口响应变慢、CPU虚高、明明内存够用但服务就是卡。
我当时的排查路径是这样的:先用jstat看GC频率和堆内存变化,再用jmap抓堆转储,最后用MAT分析对象引用关系。整个过程折腾了大半天,最后定位到一个非常不起眼的集合类使用问题。这篇文章就把整个排查思路、工具用法和参数调整经验完整记录下来,适合正在做Java开发、尤其是维护线上服务的同学参考。看完你至少能明白:遇到GC异常时,该用什么命令、怎么看日志、怎么分析堆转储、怎么调整参数,以及在写代码时怎么避免埋雷。
2. GC原理与常用参数速览
2.1 先搞懂JVM内存分代模型
想排查GC问题,脑子里必须先有一张JVM内存分代图。JVM的堆内存通常分成新生代(Young Generation)和老年代(Old Generation),新生代里面又细分为Eden区和两个Survivor区(S0、S1)。大部分对象刚创建时都放在Eden区,经过一次Minor GC仍存活的对象会被挪到Survivor区,在Survivor区来回复制达到一定年龄(默认15次)后,才晋升到老年代。
为什么这么设计?因为绝大多数对象都是“朝生夕灭”的,比如一个方法里创建的临时对象,方法执行完就没人引用它了。把这些短命对象集中放在新生代,用复制算法清理,效率高、碎片少。老年代里的对象大多是长期存活的大对象或多次GC后仍存活的对象,生命周期长,用标记-整理或标记-清除算法处理。
除了堆,还有一块经常被忽略的区域——Metaspace(元空间),JDK8之后替代了永久代,存放类的元数据信息。很多线上GC事故其实就是Metaspace不断扩容导致的Full GC。Metaspace默认是“按需扩容”的,如果加载的类太多或者没设上限,它就会一直涨,涨到一定程度触发Full GC来尝试回收类元数据,但类加载器如果不释放,回收效率极低,最后直接把CPU打满。
理解了这个分代模型,你看GC日志时会容易得多。比如下面这行日志:
background concurrent copying gc freed 7101kb allocspace bytes, 16(1496kb) l这是CMS收集器的并发复制阶段日志,意思是并发阶段(后台并发拷贝)释放了7101KB的分配空间,其中有16个对象、共1496KB是晋升(promotion)到老年代的。看到这类日志,你要意识到:老年代又多了1.5MB左右的对象,如果这个过程持续出现,说明对象晋升异常频繁,很可能是Survivor空间太小或者大对象直接进了老年代。
2.2 垃圾收集器选型与JVM参数速查
不同的垃圾收集器,在排查和调优时侧重点完全不同。现在主流的收集器有几类,我常用的排查参数也一起列出来:
| 收集器 | 适用场景 | 关键特点 | 典型启动参数 |
|---|---|---|---|
| Serial | 小内存单线程环境 | STW长,简单 | -XX:+UseSerialGC |
| Parallel | 追求吞吐量的多核服务 | GC时STW,但吞吐高 | -XX:+UseParallelGC |
| CMS | 低延迟服务 | 并发标记清除,但碎片多 | -XX:+UseConcMarkSweepGC |
| G1 | 大堆、兼顾延迟与吞吐 | 分区式,可预测停顿 | -XX:+UseG1GC |
| ZGC | 超大堆、超低延迟 | 停顿时间极短 | -XX:+UseZGC |
不管用哪种收集器,下面这几个参数都是排查GC问题的“标配”,建议直接加到JVM启动参数里:
-Xloggc:/data/logs/gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=20M参数含义:-Xloggc指定GC日志输出路径,%t会自动带上启动时间戳,防止多个进程互相覆盖;PrintGCDetails输出详细的GC前后内存变化;PrintGCDateStamps打上具体时间点;PrintHeapAtGC会在每次GC前后把整个堆的使用情况打印出来;后面三个是GC日志轮转,避免单个日志文件过大把磁盘写满。
线上环境一定要开GC日志,这个习惯能救命。很多团队怕日志占磁盘一直不开,出了问题只能靠猜,只能重新现网压测复现,效率极低。GC日志本身很小,几MB就够,比起排查时抓瞎,这点成本完全可以忽略。
3. 排查过程实录与工具选型
3.1 先用jstat观察GC频率与内存变化
接到告警后的第一步,我通常不会急着抓堆转储,而是先用jstat看当前进程的GC表现。命令很简单:
jstat -gcutil <pid> 1000 20这个命令的意思是:针对进程ID查看GC统计信息,每隔1000毫秒打印一次,总共打印20次。输出里几个核心指标要盯紧:
S0、S1:两个Survivor区的使用率,正常来说应该有明显的“一键切换”规律,一个区几乎为空,另一个区有数据;E:Eden区使用率,如果一直维持在高位不下降,说明对象分配速度极快或者清理不掉;O:老年代使用率,这是判断是否即将发生Full GC的关键指标,如果持续上升且回不去,基本可以断定老年代在膨胀;M:Metaspace的使用率,很多诡异问题出在这里;YGC、FGC:Minor GC和Full GC的次数,重点看FGC的变化速度;YGCT、FGCT:GC累计耗时,如果FGCT涨幅很快,说明每次Full GC都在“万策尽”的状态下触发。
我当时执行完,看到的结果是YGC每隔几百毫秒就一次,FGC也在一两分钟内增加了两三次,而且FGCT的累计时间涨得非常夸张。这说明服务已经处于“边分配边疯狂回收”的恶性循环里,必须立刻抓现场。
3.2 用jmap获取堆转储和堆配置
确认GC异常后,下一步就是抓堆转储(Heap Dump),看看到底什么对象霸占了内存。JDK自带的jmap是最常用的工具,关键命令有三个:
jmap -heap <pid> jmap -histo:live <pid> jmap -dump:live,format=b,file=/data/logs/heap.hprof <pid>-heap打印JVM堆参数和当前各区域使用量,能快速看清新生代、老年代、元空间的大致情况。-histo:live会先触发一次Full GC再统计对象实例数,按占用内存大小排序,能粗筛出“嫌疑对象”。-dump:live则是把存活对象的堆快照导出成hprof文件,供MAT等专业工具深入分析。
这里有个坑要注意:-dump:live会导致一次Full GC,对于已经压力很大的服务来说可能雪上加霜,严重的甚至会直接卡死几分钟。所以操作前最好和团队确认一下,或者选择服务相对空闲的窗口执行。另外,堆转储文件可能很大,几个GB都很正常,必须确保磁盘有足够空间再执行。
我之前有一次在磁盘只剩5GB的地方执行了dump,结果dump到一半磁盘写满,文件损坏,白白浪费了一次现场。后来我都是先df -h确认空间,再考虑压缩传输到本地分析。
3.3 用MAT分析对象引用与泄漏
拿到hprof文件后,我习惯用Eclipse MAT(Memory Analyzer Tool)来分析。它是目前分析堆转储最顺手的工具,打开文件后会生成一个“Leak Suspects”(泄漏嫌疑)报告,直接列出最可疑的几个对象和它们的支配树(Dominator Tree)。
MAT里最常用的视图有三个:
- Histogram(直方图):按类统计实例数和占用的堆内存大小,快速找到“哪个类的对象最多”。比如看到
byte[]占了几个G,那就要继续找谁持有这些byte[]。 - Dominator Tree(支配树):从堆内存的“根部”往下看,哪个对象持有了一大批子对象,谁是真正的“内存大户”。
- Path to GC Roots(到GC根的路径):选中一个对象,查看它为什么无法被回收,顺着引用链找到底是哪个业务代码一直握着它不放。这是判断内存泄漏的关键,如果从GC Root到这个对象有一条强引用链,那它就不会被回收。
有次我通过MAT发现,一个ConcurrentHashMap里存放了几百万个缓存Key,这些Key是数据库查出来的批次号,本应设置过期时间,结果代码里只往Map里put,却没有逻辑做清理,导致Map不断膨胀。顺着Path to GC Roots很轻松就追到了这段代码,定位效率非常高。
3.4 解析GC日志中的关键信息
堆转储分析的是“瞬时快照”,而GC日志记录的是“历史过程”。两者结合才能还原完整的时间线。GC日志里常见的两种日志格式要会读。
Minor GC日志大致长这样:
2025-02-18T14:23:01.496+0800: 325.478: [GC (Allocation Failure) [PSYoungGen: 754688K->5231K(787968K)] 754688K->152343K(3058688K), 0.0212341 secs] [Times: user=0.06 sys=0.02, real=0.02 secs]解读:14:23:01那一刻,JVM运行了325.478秒时发生了一次Young GC,原因是“分配失败”。新生代从754688KB降到5231KB,占用率很低说明回收效果不错;但整个堆从754688KB只降到152343KB,说明有一部分对象被晋升到了老年代。这个754688K->152343K的差距非常关键:如果经常出现“新生代回收很多,但堆总占用下降很少”的日志,说明对象晋升率高得离谱,老年代迟早被塞满。
Full GC日志则会有"Full GC"字样,比如:
2025-02-18T14:25:10.101+0800: 513.223: [Full GC (Ergonomics) [PSYoungGen: 4096K->0K(1572864K)] [ParOldGen: 2873855K->2873376K(3140608K)] 2877951K->2873376K(4713472K), [Metaspace: 98562K->98562K(1258496K)], 3.2156720 secs]这条就典型了:老年代从2873855KB只回收了479KB,Metaspace一点没变,整整停了3.2秒。这说明搞了一次“无效Full GC”,堆里塞满了一堆清理不掉的对象,这种情况不抓堆转储根本看不出来是什么东西。
再回到开头的background concurrent copying gc freed 7101kb allocspace bytes, 16(1496kb) l,如果你用的是CMS收集器,在日志里会频繁看到类似的并发阶段输出。background concurrent copying是CMS的并发拷贝(也叫并发预清理)阶段,freed 7101kb表示清理了7000多KB,16(1496kb) l翻译过来是“有16个对象、共1496KB晋升到老年代”。这条日志本身不一定是坏事,它是CMS在后台并发干活时打印的,但如果频繁出现且l后面数值偏大,就说明Survivor区总是放不下晋升对象,需要关注Survivor空间配置或者晋升阈值设置。
4. 根因分析与解决措施
4.1 案例一:大对象直接进入老年代
有一次排查某服务GC高频问题,发现老年代涨得特别快,但代码里没有明显的集合类缓存。后来翻GC日志发现,每次大对象分配时日志都会带-XX:PretenureSizeThreshold超限的迹象。简单解释:JVM有个参数叫-XX:PretenureSizeThreshold,默认是0,表示不启用“大对象直接进老年代”的机制。如果手动设置了这个值,比如设成1MB,那么超过1MB的byte数组或对象会被直接分配到老年代,不经过新生代。
这种大对象进入老年代后,如果程序频繁构造大数组(比如读取大文件、处理图片、批量导出Excel),老年代就会像吹气球一样迅速膨胀。这些大对象一旦用完且引用断开,理论上是可以回收的,但因为它们都堆在老年代,导致老年代GC频繁。而且CMS收集器对老年代做并发标记时,如果大对象很多,会带来严重的碎片化问题,最终可能触发Concurrent Mode Failure,直接退化为Serial Old收集,那STW时间能到几十秒。
解决办法分两个层面:代码层面,尽量避免创建超大数组,能分块处理就不要一次性load到内存;JVM参数层面,如果大对象确实免不了,可以尝试调大新生代空间,让大对象在新生代经历一次GC再晋升,或者适当调大-XX:PretenureSizeThreshold,让更大阈值的对象留在新生代(前提是新生代空间够大)。但最稳妥的方案还是从代码上避免大对象频繁生成,参数只是兜底。
4.2 案例二:Metaspace扩容导致Full GC
还有个典型场景,服务升级到JDK8之后,没设置-XX:MaxMetaspaceSize,结果Metaspace默认会随着类加载不断增加。如果是动态生成类的框架(比如CGLIB代理、反射生成大量Proxy类、热部署),会快速打满Metaspace,触发Full GC来回收废弃的类元数据。但很多框架生成的类是被类加载器长期持有的,回收不掉,于是每次Full GC都“回收无果”,白白停顿几秒。
我遇到过一次比较极端的:某个服务用了动态报表引擎,每次用户查询都会通过ASM生成新的临时类,一天几百万次查询,Metaspace涨到1GB多,Full GC每10分钟一次,每次停顿4秒以上。排查时GC日志里的[Metaspace: 98562K->98562K(1258496K)]永远不变,说明没东西可回收。
解决方式:先给Metaspace设置合理上限,-XX:MaxMetaspaceSize=256m,配合-XX:MetaspaceSize=128m让JVM提前触发回收;再从代码层面排查是否真的有必要动态生成这么多类,能用缓存类复用就不要每次都新生成。对热部署场景,还要注意类加载器泄漏——老类加载器被业务对象间接持有,导致整个Metaspace无法释放。
4.3 案例三:集合类长期持有关键对象
内存泄漏里最常见的就是集合类持有的问题。我在排查那个“接口耗时飙升”案例时,用MAT找到根因就是某个HashMap的table数组占用了1.2GB,里面有几十万条Entry,Value是一个个自定义的业务对象,每个对象又引用了一个byte[](数据库查出来的原始报文)。
这个Map按理说应该只缓存最近5分钟的数据,但代码里只在写入时检查了Map大小,当超过阈值时清空整个Map。问题出在并发场景下,多个线程同时执行了“先get后put”的逻辑,清空操作被某个线程的put覆盖掉,导致Map永远清不干净。本质上就是一个典型的“缓存没有过期策略且并发控制有漏洞”的问题。
这个案例的教训很深刻:不是所有缓存都值得用Map硬扛,线上系统需要根据业务特性选择合适的缓存组件。数据量小可以用ConcurrentHashMap配合LinkedHashMap实现LRU,数据量大就直接上Caffeine或Redis。如果不想改架构,最懒但有效的办法是给Map设置size上限后,用remove(最旧元素)的逻辑代替clear(),至少保证内存不会被无限撑爆。
4.4 如何针对性调整JVM参数
调整JVM参数的目标就两个:要么减少GC次数,要么缩短单次GC停顿时间。但这两个目标有时候是相互矛盾的,所以调整前必须明确当前瓶颈在哪。
如果Young GC太频繁,说明新生代空间太小。可以调大-Xmn(新生代大小)或者调整-XX:NewRatio(老年代和新生代的比例,默认2,即老年代占2/3)。空间变大了,对象能扛住的分配周期变长,Young GC自然就少了。但要小心代码里如果创建大量的短生命周期对象,堆整体占用还是会不变,只是“延迟”了GC的触发而已。
如果Full GC太频繁,优先看老年代为什么塞满。如果是因为对象晋升太快,可以调大Survivor区比例-XX:SurvivorRatio(默认8,即Eden区占新生代的8/10),或者提高晋升年龄阈值-XX:MaxTenuringThreshold,让对象在Survivor区多熬几次GC再进老年代。如果是因为元空间满了,就设置合适的-XX:MaxMetaspaceSize。
如果是单次GC停顿时间过长,比如超过1秒,而且你的服务对延迟很敏感,那就应该考虑换G1或者ZGC收集器。G1可以通过-XX:MaxGCPauseMillis指定期望的最大停顿时间(比如200ms),但它只是一个软目标,JVM会尽力调整分区大小来满足。ZGC则几乎把停顿时间控制在10ms以内,但代价是CPU占用更高、需要JDK11以上版本。
调参必须基于排查结果来,不要一上来就拍脑袋“把堆内存调大”。很多新手遇到GC问题就-Xmx8g -Xms8g往上怼,结果堆大了,单次GC时间反而更长,问题更严重。正确的姿势是:先定位对象增长原因,再决定是改代码还是调参数,参数只是辅助。
5. 常见问题与排查技巧实录
5.1 常见异常速查表
| 异常/现象 | 典型原因 | 首选排查手段 | 常用的解决方向 |
|---|---|---|---|
java.lang.OutOfMemoryError: GC overhead limit exceeded | GC一直在回收但回收效果极差,堆基本被无效对象占满 | jstat -gcutil看FGC次数,抓堆转储分析 | 确认是否内存泄漏,用MAT找根因;临时调大堆内存并配合代码修复 |
java.lang.OutOfMemoryError: Java heap space | 堆内存被耗尽,无法再为新对象分配空间 | jmap -heap看各区域用量,jmap -histo看对象数量 | 找到占用大头并优化;合理设置-Xmx,但关键是排查是否泄漏 |
java.lang.OutOfMemoryError: Metaspace | 动态生成类过多或Metaspace上限设置过小 | 看GC日志中Metaspace的使用趋势,检查类加载器 | 设置-XX:MaxMetaspaceSize,修复类加载器泄漏 |
java.lang.OutOfMemoryError: unable to create new native thread | 线程数超过系统限制 | ulimit -u查看限制,jstack统计线程数 | 检查是否存在线程泄漏,合理使用线程池,减少不必要的新线程 |
GC日志频繁出现Concurrent Mode Failure | CMS收集器并发清理时,老年代内存不足以容纳新晋升对象 | 分析晋升对象大小,调大老年代空间或提前触发Full GC | 调整-XX:CMSInitiatingOccupancyFraction(触发阈值,默认68%),预留更多空间 |
| 接口偶发性超时,CPU飙升但堆内存正常 | 可能是GC之外的死循环/锁竞争,或编译优化导致 | jstack抓线程栈,top -Hp看线程CPU占用 | 定位对应代码逻辑,修复死循环或优化锁 |
排查GC问题时,我习惯把异常现象和日志信息结合起来看,而不是只看异常名去百度。GC overhead limit exceeded这个异常,翻译过来就是“JVM花了超过98%的时间在做GC,但回收不到2%的内存”,它本质上只是“堆快满且GC无效”的告警,别被异常名带偏,还是要靠堆转储去看是什么占着内存。
5.2 那些年踩过的坑与实操心得
这么多年排查GC问题,踩过的坑数不胜数,挑几个最典型的分享一下。
坑一:用jmap -histo:live误伤线上服务。live参数会先触发Full GC,我遇到过在高峰期执行这条命令直接让服务STW了十几秒,从此再也不敢乱用。现在我的习惯是:先看服务器负载,如果CPU已经过高,用jmap -histo(不带live)先看个大概,把嫌疑范围缩小后再挑低峰期做dump。
**坑二:堆转储文件太大,本地分析直接OOM。**MAT默认分配堆内存是1GB,而线上堆如果有4GB,分析时MAT自己就先内存溢出了。解决办法是修改MAT安装目录下的MemoryAnalyzer.ini,把-Xmx调大到比如8G。另外,分析hprof文件很吃内存,建议在单独的16GB内存机器上分析,否则分析过程中会卡到怀疑人生。
**坑三:只看Hprof文件不看GC日志,导致判断失误。**堆转储只能看到当前时刻的内存快照,看不到历史趋势。有些对象在dump时占内存特别多,不一定是泄漏,可能是某次大查询恰好没释放。GC日志则能还原GC频率、耗时、前后内存变化的全过程,两者配合才能下结论。我现在排查的标准动作是:先看GC日志的趋势,再抓dump验证对象引用关系,最后review代码确认根因。
**坑四:修复之后没有做GC对比验证。**很多人改完代码或者调完参数就以为完事了,不看修复后的GC日志。我一般会在修复后观察至少24小时的GC曲线,对比修复前后的YGC、FGC次数和FGCT耗时。因为有些问题是间歇性触发的,短时间内看不出效果,只有等完整业务周期跑完才能确认没复发。
**坑五:线上环境没有开启GC日志,遇到问题只能靠猜。**这个坑最致命。我强烈建议所有Java服务,无论环境大小,都加上GC日志参数。就算你觉得参数调得再好,日志就是事后追溯的“黑匣子”,没它你都不知道自己改的对不对。开日志的开销几乎可以忽略不计,关键是它能在出问题时让你有个可以依靠的证据链。
最后再分享一个小技巧:排查GC问题时,不要只盯着GC相关的东西。有时候业务代码的某个SQL一次性把几百万行数据查出来放到内存里,直接就把老年代打穿了,你在这边调半天GC参数,不如把SQL加个limit。工具是辅助,真正决定问题是否解决的是你对业务代码和内存分配模式的理解。GC问题的本质从来不只是JVM调优,更多时候是代码写得好不好的问题。