搞IT这些年最怕听到的不是需求变更而是晚上十点手机一响电话那头蹦出四个字服务挂了。挂的原因千奇百怪但排到最后十有七八都跟GC有关系。前阵子还有同事跑来问我说git拉取代码一直卡在fetch命令行反复提示see help gc for manual housekeeping问我怎么弄。我一看这不就是git仓库的对象数据需要做垃圾回收整理了嘛。同样是GC计算机世界里的Garbage Collection从来都是件大事——git仓库膨胀了要gcJVM堆内存满了更要gc。区别在于git的gc按一下命令行就行JVM的gc一旦出问题那就是CPU飙升、接口超时、系统雪崩。这一章我就把这几年在GC问题排查上踩过的坑、试过的招、总结出的套路完整梳理一遍。不管你是刚接触JVM调优的初学者还是已经被线上Full GC折磨过的老手这里面讲的排查思路和实操命令都能直接用在你自己的项目里。我们不聊虚的全部是实打实的定位过程和修复方案。1. 排查GC问题前先把这些底层逻辑盘清楚很多人一遇到GC问题就急着翻日志、调参数结果东一榔头西一棒子越弄越乱。我自己的习惯是动手之前先花几分钟把几个关键问题想明白当前JVM用的是什么垃圾回收器堆内存怎么划分的GC日志有没有开这三个问题没搞清楚后面的所有操作都是盲人摸象。1.1 GC到底在回收什么别把对象生命周期搞混GC回收的对象是那些没有任何引用指向它们的堆内存对象。这个听起来简单但实战里经常有人搞混一个概念可达性分析。JVM从GC Roots出发沿着引用链往下遍历能走到的对象就标记为存活走不到的判定为可回收。GC Roots包括虚拟机栈中引用的对象、静态属性引用的对象、常量引用的对象、JNI引用的对象等等。理解这个模型最大的用处是排查内存泄漏时你能顺着引用链条逆推。比如用jmap dump出堆快照后用MAT分析看一个对象为什么没被回收本质上就是看谁还在引用着它。实际工作中我见过太多类似对象明明不用了却一直被某个静态集合持有的案例这种问题不搞懂可达性分析光调堆大小是根本治不好的。1.2 分代模型与GC器选型为什么不同版本差异这么大JVM的堆内存分代模型简单说就是新生代和老年代两块区域。新生代再细分成Eden区、两个Survivor区S0和S1新对象大部分出生在Eden区经过几次Minor GC还活着的对象逐步晋升到老年代。不同JDK版本默认的垃圾回收器差别很大这点经常被忽略。JDK 8默认是Parallel Scavenge新生代 Parallel Old老年代追求的是吞吐量JDK 11以后G1成了默认G1把堆划分成很多Region既能处理年轻代也能处理老年代通过-XX:MaxGCPauseMillis来控制停顿目标再往后还有ZGC主打低延迟适合超大堆场景。拿我自己踩过的坑来说有次排查一个JDK 8的项目发现服务频繁Full GC团队第一反应是加堆内存。但实际一看项目里大量使用了JAXB做XML解析每次解析都会通过反射生成临时类导致Metaspace持续增长最终触发Full GC。这种问题光加堆内存完全没用因为元空间属于堆外内存得单独关注。选对分析方向比盲目调参重要十倍。1.3 排查前的工具清单与准备我排查GC问题时一般会按顺序准备这几样东西GC日志最基础、最可靠的现场证据。如果线上服务没开GC日志等于事故现场被破坏了大半后续全凭猜。jstatJVM自带的统计工具能实时观察堆各区域使用情况、GC次数和GC耗时。jmap生成堆转储快照排查内存泄漏、分析对象分布时必备。jstack抓取线程快照配合GC问题定位是不是线程层面引起的资源竞争。MAT或JProfiler分析dump出来的堆文件查找可疑大对象、重复对象。Arthas阿里开源的Java诊断工具线上热排查神器很多场景下比前几个工具更灵活。注意jmap在JDK 8和JDK 11的用法差别很大。JDK 11之后jmap被整合进了jhsdb工具直接用jmap -dump在某些版本里已经不生效了。排查前先确认你手里JDK的版本避免现场手忙脚乱。2. GC日志问题现场的第一手证据GC日志是排查GC问题最重要的依据。我把GC日志比作事故现场的行车记录仪——别人跟你说服务卡了你看了日志才能知道卡在哪里、卡了多久、是Minor GC还是Full GC造成的。遗憾的是很多项目的GC日志压根就没开导致每次出问题都只能事后靠猜。所以这一节我们先解决怎么让JVM好好记录现场的问题再教你如何把日志读出信息量。2.1 让JVM开口说话GC日志参数怎么配GC日志参数这块不同JDK版本的写法有很大差异这里我先列一个基于JDK 8的配置模版这也是目前生产环境最常见的情况-Xloggc:/opt/logs/gc.log -XX:PrintGCDetails -XX:PrintGCDateStamps -XX:PrintGCTimeStamps -XX:PrintHeapAtGC逐一解释一下-Xloggc指定GC日志的输出路径注意生产环境一定要放在独立的磁盘分区避免日志写满根分区-XX:PrintGCDetails输出详细的GC事件信息包括各代空间的前后变化-XX:PrintGCDateStamps会在每条GC日志前加上日期时间方便跟业务报障时间对齐-XX:PrintGCTimeStamps输出JVM启动后的运行秒数-XX:PrintHeapAtGC会在每次GC前后把堆各区域的使用情况完整打印一遍。进入JDK 11及以后日志参数统一改成基于-Xlog的格式-Xlog:gc*:file/opt/logs/gc.log:time,uptime,level,tags这种写法更灵活gc*表示输出所有GC相关标签的日志后面跟输出文件、时间格式、日志级别等配置。说句实在话参数变了但核心思想没变你要能从中看到GC发生的时间点、GC类型、各区域内存变化、耗时。2.2 从头到尾读懂一行GC日志光配上参数还不够关键是要能读明白日志里的信息。拿最常见的Parallel GC日志举例假设某次日志长这样[GC (Allocation Failure) [PSYoungGen: 65536K-10240K(76288K)] 65536K-18944K(251392K), 0.0142906 secs] [Times: user0.02 sys0.01, real0.01 secs]我来拆解一下。开头的中括号里可以看到GC类型这里是GC (Allocation Failure)意思是新生代分配失败触发的Minor GC。后面跟着[PSYoungGen: 65536K-10240K(76288K)]表示新生代GC前占用65536KGC后占用10240K新生代总容量76288K。再往后的65536K-18944K(251392K)表示整个堆在GC前的占用是65536KGC后降到了18944K堆总容量251392K。最后是耗时0.0142906秒Times里的user、sys、real分别代表用户态CPU时间、内核态CPU时间和真实耗时。再看Full GC日志[Full GC (Ergonomics) [PSYoungGen: 10240K-0K(76288K)] [ParOldGen: 225152K-235152K(175104K)] 235392K-235152K(251392K), [Metaspace: 10245K-10245K(1069056K)], 0.3456789 secs]注意看这里有个非常关键的信号这次Full GC之后老年代从225152K涨到了235152K内存不但没有降下去反而增加了。这说明什么说明老年代里堆积的对象全是存活的GC根本回收不掉——这往往是内存泄漏或者对象晋升速度过快的强提示。2.3 日志之外jstat与可视化工具怎么看GC日志是事后分析排查正在进行中的问题时jstat才是实时监控的主力。命令很简单jstat -gcutil pid 1000 10-gcutil参数会以百分比形式输出各区域的使用情况每1秒打一次共打10次。输出的列里S0、S1是两块Survivor区的使用率E是Eden区使用率O是老年代使用率M是Metaspace使用率YGC和YGCT分别代表Minor GC次数和总耗时FGC和FGCT是Full GC次数和总耗时GCT是全部GC的总耗时。实战里我拿到gcutil输出后会做三个快速判断如果E区频繁从接近100%掉到接近0说明Eden区对象分配和回收都很活跃Minor GC频率高不一定是坏事但要结合对象晋升情况看如果O区持续爬升且Full GC后降幅很小基本可以怀疑有对象堆积如果M区持续增长那要重点查动态类加载、反射、CGLIB代理这些点。可视化方面VisualVM适合本机或测试环境用能直观看到堆内存曲线和GC情况。生产环境我强烈推荐阿里开源的Arthas它可以用dashboard命令实时查看内存、线程、GC状态还能用jad反编译线上类、用watch监控方法入参返回排查问题的效率提升不止一个档次。3. 从现象到根因三类典型GC问题的定位思路GC问题现象千变万化但归结起来其实就三类Minor GC太频繁、Full GC太频繁/太慢、GC停顿时间过长。我这些年累计排查过几十起线上GC问题每一类都有自己的定位套路。下面逐个拆开讲。3.1 频繁Young GC对象分配速率异常Young GC频繁本质是新生代空间不够用。但不够用背后的原因却五花八门。最常见的是对象分配速率过高也就是单位时间内创建的对象太多Eden区被迅速填满只能频繁触发Minor GC。怎么判断是分配速率高而不是堆太小我常用一个办法连续用jstat -gcutil采一段时间数据假设Eden区容量是2GB每10秒填满一次每分钟触发6次Minor GC。如果每次Minor GC后S0/S1区的对象占用不大老年代增长也不明显基本可以判断是临时对象大量产生。这种情况我会先去代码里找热点创建对象的位置。怎么找用jstack连续抓几份线程快照看哪些线程频繁出现在某个业务代码段上或者用Arthas的profiler命令做CPU采样直接看热点方法。之前排查过一个数据导入服务每分钟触发20多次Minor GC最后定位到是Excel解析时一次性把整张表的数据读进了内存改成流式解析后GC频率直接降了一个数量级。如果确认是堆太小那就调整堆参数。这里有一个必须养成的习惯线上服务启动参数里的-Xms和-Xmx必须设成相同值。否则JVM会在运行期动态伸缩堆大小伸缩过程本身就会触发Stop The WorldSTW。设成相同值后堆容量固定JVM启动时一次性申请到位避免运行时伸缩。3.2 频繁Full GC堆内与堆外都要查Full GC是生产环境的头号杀手它意味着整个堆的存活对象都会被扫描STW时间通常比Minor GC长得多。Full GC触发原因主要有四类老年代空间不足、Metaspace空间不足、显式调用System.gc()、CMS的并发模式失败或晋升失败使用CMS时。老年代空间不足是最常见的。流程上我会分两步走先看老年代里装的是什么再想这些对象为什么没被回收。# 第一步查看堆中各区域的实时占用 jstat -gcutil pid 1000 5 # 第二步查看堆中对象实例数量与占用大小排行 jmap -histo pid | head -50jmap -histo输出的结果里重点关注两列实例数量和字节数。如果你发现某个业务对象动辄几十万上百万个实例而且占了大量内存那基本可以确定它是内存增长的元凶。接下来就得用jmap -dump把堆快照导出来用MAT或者JProfiler做更深层的分析看这个对象是被谁引用着。Metaspace导致的Full GC是个经典的隐形坑。Metaspace存放类的元数据属于堆外内存很多人的监控面板只看了堆内存压根注意不到它。如果你发现Full GC频繁但堆各区域占用都很正常一定要用jstat -gcutil里的M列看Metaspace使用率。如果M持续上涨且GC后不回落就要排查是不是有动态生成类的代码在运行——CGLIB代理、反射调用、热部署框架这些都是Metaspace增长的高发源头。那System.gc()引发的Full GC呢很多框架和中间件的代码里会显式调用System.gc()来主动清理但实际上这会强制触发Full GC给整个应用带来不可控的停顿。排查时可以加启动参数-XX:DisableExplicitGC来禁止显式GC调用。不过要注意Netty这类使用堆外内存的框架在某些情况下需要显式GC来触发堆外内存回收禁用前要确认你使用的框架没有这种依赖。稳妥的做法是加参数-XX:ExplicitGCInvokesConcurrent把System.gc()触发的Full GC降级为并发GC这样既能配合框架需求又不会导致长时间STW。3.3 GC停顿时间过长STW的背后GC必然会停顿但停顿时间过长就说明有问题了。我记得有一次线上现象是服务每半小时卡顿一次每次卡顿二三十秒整个集群的接口超时率飙升。翻GC日志一看每次卡顿都对应一次老年代GC每次耗时20秒以上。这种单次GC耗时长的根因排查我一般按从易到难的顺序来先看是不是堆太大导致扫描时间长再看是不是GC线程数配置不合理最后看是不是业务代码在GC前后触发了大量额外操作比如finalize方法、对象头中的锁竞争。堆太大这个问题比较拧巴——堆小了频繁GC堆大了单次GC慢。G1和ZGC这类分区式回收器就是为了解决这个矛盾。如果你的JVM是G1但MaxGCPauseMillis设置得过大或者为0G1就不会主动控制停顿时间。我习惯把-XX:MaxGCPauseMillis设在100~200ms之间然后观察实际GC日志里的停顿是否接近这个目标。如果仍未达标优先调整-XX:G1NewSizePercent和-XX:G1MaxNewSizePercent来限制年轻代Region数量而不是无脑加大堆。提示GC耗时长还有一个极容易忽略的元凶——JVM的偏向锁撤销。高并发场景下大量对象在GC前后发生锁状态变化可能造成额外开销。如果确认业务有大量synchronized同步块可以考虑加-XX:-UseBiasedLocking关闭偏向锁某些场景下会有立竿见影的效果。4. 实战案例一次线上Full GC排查全过程前面讲的都是方法论这一节我拿一个真实的线上故障来串一遍完整排查过程。这个案例是我去年处理过的现象典型、定位路径清晰很适合用来演示。4.1 现象与初步判断某天下午运营反馈后台管理系统响应极慢点一个按钮要转好几圈才出结果。我上运维平台一看监控CPU使用率持续高位接口平均响应时间从200ms飙到3秒多同时JVM监控里Full GC次数曲线垂直上升。当时第一反应就是老年代GC出问题了。登录服务器先用jstat确认现状jstat -gcutil 12345 1000 10输出结果里O区从56%一路涨到99%FGC次数在10秒内增加了3次FGCT也从几秒涨到了十几秒。基本可以判定是老年代空间快速耗尽导致的频繁Full GC。4.2 jstat/jmap/jstack三件套定位老年代频繁GC要回答两个问题老年代里积累了什么东西是什么代码造成的先用jmap -histo看看对象分布jmap -histo 12345 | head -30结果看到有个名为cn.xxx.config.UserAuthInfo的对象实例数高达80多万占了老年代近5GB的空间。看一眼代码发现这是一个用户认证信息的实体类按理说认证完成后对象就该被丢弃不可能积压这么多。接着用jstack抓线程快照jstack 12345 /tmp/thread_dump1.txt # 隔5秒再抓一次 jstack 12345 /tmp/thread_dump2.txt两份线程快照对比下来发现业务线程A和线程B反复出现在同一个方法栈——一个定时任务在不停地调用登录状态刷新接口每次刷新都创建一个新的UserAuthInfo对象且没有释放旧对象。为了确认对象是被谁持有我dump了一份堆快照jmap -dump:formatb,file/tmp/heap.hprof 12345用MAT打开后用Dominator Tree分析发现UserAuthInfo全部堆积在一个静态的HashMap里。这个Map由某个配置中心组件维护每次配置变更就往里塞一份新的认证信息但代码里只写了put逻辑从未清理。这就是典型的静态集合持有对象导致的内存泄漏。4.3 兜底优化方案与长期治理策略临时方案很直接把那台服务器从负载均衡上摘下来重启应用内存恢复正常服务迅速恢复。但这只是治标不重启迟早还会再炸。修复方案有两层。第一层是代码层面给那个静态Map加容量上限超过阈值后按FIFO策略淘汰旧数据同时在配置变更时清理不再使用的认证信息。第二层是配置层面针对这类会长时间运行的后台服务我把启动参数做了几个固定调整-Xms4g -Xmx4g -XX:UseG1GC -XX:MaxGCPauseMillis200 -XX:HeapDumpOnOutOfMemoryError -XX:HeapDumpPath/opt/logs/-Xms和-Xmx相等避免堆动态伸缩换成G1并设置停顿目标减少大堆下的长停顿加上HeapDumpOnOutOfMemoryError万一以后再出OOM至少能留下堆快照这个现场。长期治理角度我在团队里推了两件事一是所有线上Java服务强制开启GC日志日志统一采集到ELK方便事后回溯二是建立GC监控告警Full GC频率超过阈值就自动报警。后来同类问题在别的项目里又出现过一次靠着GC日志和监控告警团队在用户还没感知时就完成了定位和修复。5. 实战复盘常见问题速查表与避坑指南这一段算是把我自己的经验浓缩成一份可查的清单。碰到GC问题不知道从哪下手时拿出来对着看能少走不少弯路。5.1 高频问题速查现象可能原因快速定位方法常用处置方案Young GC频繁但堆内存充足对象分配速率高、临时对象多jstat观察Eden区回收曲线jstack查热点线程优化代码减少对象创建调整新生代比例Full GC频繁老年代持续增长内存泄漏 / 大对象直接进入老年代jmap -histo看对象排行jmap -dump MAT分析引用链修复泄漏代码设置大对象阈值Full GC频繁但堆内存占用低Metaspace增长 / 显式System.gc()jstat观察M区检查启动参数排查动态类生成加-XX:DisableExplicitGCGC单次停顿时间过长堆过大 / G1停顿目标设置不合理GC日志查看单次耗时调整GC器参数限制年轻代RegionGC后老年代占用不降反升对象大量存活 / 晋升阈值设置不当GC日志对比GC前后Old区变化调大晋升阈值优化缓存淘汰策略5.2 排查工具与参数避坑清单罗列几个我真实踩过的坑希望你别再踩一遍。第一不要在内存紧张时直接用jmap -dump抓完整堆快照。jmap -dump:live会先触发一次Full GC再导出线上场景下这么做可能直接把服务搞挂。稳妥做法是先加-XX:HeapDumpOnOutOfMemoryError让JVM在OOM时自动抓快照确需手动抓取时优先使用gcore或jhsdb jmap这类不触发Full GC的方式并在低峰期操作。第二jstat采样的时间跨度至少要覆盖一次完整的GC周期。只看一两秒的快照数据没有意义新生代刚好在GC后被采到和刚好在GC前被采到数字天差地别。我一般是5秒一次、连续采样20次以上再结合趋势曲线判断。第三不要忽略业务线程栈与GC日志的关联分析。GC日志告诉你发生了什么线程快照告诉你是谁引起的两者结合才能精准定位。我见过太多人拿着GC日志调了一下午参数最后发现是某个定时任务在凌晨批量跑数据把堆塞爆了。第四G1的-XX:PrintGCDetails输出格式跟CMS完全不同。G1的日志里没有PSYoungGen、ParOldGen这种区块而是按Region的回收事件来打印比如G1 Evacuation Pause (young)、G1 Humongous Allocation。如果拿CMS时代的经验硬套G1日志很容易误判GC类型。排查前先确认当前JVM用的什么GC器再看对应格式的日志。第五调参要一次只调一个变量。GC调优里有个经典错误同时改堆大小、改GC器、改阈值出了效果也不知道是谁的功劳出了问题也不知道该回滚哪个。我的做法是每次只改一个参数压测验证后再动下一个每步都有记录。第六Arthas确实好用但生产环境使用要谨慎。Arthas的attach会修改目标JVM的字节码注入个别场景下可能触发安全软件拦截也可能影响应用的稳定性。如果公司有严格的变更管控流程先在测试环境验证没问题再上生产或者使用阿里云ARMS这类专业的APM产品替代。6. 最后再分享一个小技巧我个人在实际排查中习惯用一套三分法来组织思路先花三分时间看GC日志和监控指标明确发生了什么再花七分时间用jstat、jmap、jstack定位为什么发生。不要一上来就改参数大多数GC问题都不是参数惹的祸而是代码里的内存管理出了问题。还有一个从git gc那个提示联想到的小经验git仓库膨胀了可以手动执行git gc --aggressive来整理JVM也一样别等到内存爆了才想起做治理。平时多留意一下项目的对象创建逻辑尤其是缓存、静态集合、线程池这些容易隐藏引用关系的角落比任何时候的紧急排查都管用。希望这份实战记录能帮你在下一次GC告警到来时少一点手忙脚乱多一点从容。