做Java后端这几年每逢应用发布前被问最多的问题之一就是JVM堆内存怎么设垃圾收集器用哪个其实很多时候答案早就在GC日志里躺着只是没几个人肯耐心去看。JVM的垃圾收集器、GC日志分析、HotSpot、JDK1.8这四个关键词凑在一起基本就是一次线上诊断的完整闭环。这篇文章不打算把规范文档复述一遍而是想从HotSpot在JDK1.8环境下的真实行为出发把“有哪些收集器、它们分别在什么场景下干活、日志里每一行都说了什么、怎么看日志发现问题”这条线彻底捋顺最后给一份可以直接照着背的GC思维导图结构。不管你是刚接手线上服务的新人还是已经有几年经验但一直靠经验猜配置的老手这轮内容应该都能对得上。1. JVM垃圾收集器全景从分代模型到HotSpot实现1.1 为什么JDK1.8默认组合是PSParallelOld很多人一开始接触垃圾收集器的时候都会被一堆名字砸晕Serial、ParNew、Parallel Scavenge、CMS、G1还有一堆Old。但如果把视角拉回到JDK1.8这个具体版本会发现默认组合其实很固定新生代用Parallel Scavenge老年代用Parallel Old。这也是Oracle JDK和OpenJDK在8u系列里长期保持的默认策略。这里首先要理解分代模型的出发点。HotSpot把堆分为新生代和老年代目的是让不同生命周期的对象走不同的回收路径。绝大多数对象“朝生夕灭”在新生代就能被清理掉没必要把它们挪到老年代再花大代价整理。新生代内部又分成Eden区和两个Survivor区默认比例是8:1:1。这个比例我见过不少项目改过但说实话大多数业务场景默认值就够了乱改反而会让对象在Survivor之间来回拷贝或者提前晋升。那为什么默认不是CMS更不是G1而是Parallel Scavenge Parallel Old因为JDK1.8的默认面向的是“吞吐量优先”场景。Parallel系列的核心理念是让垃圾收集线程和应用线程并行执行尽可能让CPU花更多时间在业务上而不是频繁停顿。用官方的话说它关注的是“通过调整停顿时间上限来间接控制吞吐量”但实际上PS系列更偏重吞吐量最大化。对大多数无状态服务、批量计算任务、内部管理系统来说这种组合最省心。这里有个容易踩的认知误区很多人觉得CMS才是默认因为网上文章提到CMS多实际上那个时代CMS常见于低延迟场景需要手动指定。如果你在启动命令里什么都没加JDK1.8跑起来的收集器就是PSPO。所以看GC日志时看到PSCON和ParOld时不要慌那不是异常也不是配了什么怪东西那就是默认组合的名字。1.2 七大收集器核心对比与选型逻辑要真正看懂GC日志至少得先把HotSpot在JDK1.8里能用的收集器记个大概。我把它们整理成一个粗线条的对比表重点不是参数而是“它们关心什么”。收集器分代线程模式主要目标典型场景Serial新生代单线程简单、低内存开销客户端应用、小堆、单核ParNew新生代多线程并行配合CMS服务端新生代并行回收Parallel Scavenge新生代多线程并行吞吐量优先后台任务、批量计算Serial Old老年代单线程兜底、CMS失败后备小堆、串行环境Parallel Old老年代多线程并行吞吐量优先配合Parallel ScavengeCMS老年代并发标记清除低延迟交互型服务、响应敏感G1不分代逻辑上Region多线程并发可预测停顿大堆、JDK8后期调优主流这张表里有一个关键点CMS是标记-清除所以会产生碎片而Parallel Old是标记-整理会移动对象。碎片的影响在日志里不会直接显示但会导致老年代明明还有大量空闲空间却没办法给大对象分配连续区域最后触发Full GC。这是CMS被嫌弃的核心理由之一。选型逻辑其实不复杂。如果你的应用是Web接口、实时性要求高、单次请求响应时间重要那CMS或JDK8下的G1通常更合适。如果你的应用是离线计算、吞吐量要求高、偶尔一次停顿可以接受那默认的PSPO就是好搭档。最怕的是“不知道自家默认是什么却按网上CMS调优文章把参数抄一遍”那样日志看不懂问题也照不出来。1.3 一个容易被忽略的点收集器与内存分配策略的关系垃圾收集器不是独立工作的它跟对象分配策略耦合很深。很多GC日志看似奇怪的现象根源其实在分配策略上而不在收集器本身。HotSpot的对象分配顺序大致是这样新对象优先在Eden区分配Eden区空间不足时触发Minor GC。如果一个对象体积太大超过了“大对象直接进入老年代”的阈值就会直接进老年代。这个阈值可以通过-XX:PretenureSizeThreshold设置但需要注意它只对Serial和ParNew生效对Parallel Scavenge并不直接生效。很多人在网上看到“通过这个参数避免大对象频繁在新生代拷贝”结果发现没效果就是因为默认收集器是Parallel Scavenge该参数不生效。除了大对象还有一个动态年龄判定。对象在Survivor区每熬过一次Minor GC年龄加一默认累积到15岁进入老年代。同时HotSpot还有一个动态机制如果Survivor区中同一年龄的对象大小总和超过Survivor空间的一半那么年龄大于等于这些对象的对象直接晋升老年代。这个机制在日志里不会打印但会导致某些对象比预期更早进入老年代进而影响Full GC频率。明白了分配策略再去看GC日志里的“Allocation Failure”就有另一个层次的理解。Allocation Failure是触发Minor GC最常见的GC Cause解释为“我准备分配新对象但Eden区空间实在不够了”。它不是一个错误而是一个常规事件。你要是把日志里的Allocation Failure当成异常去查大概率会空手而归。2. GC日志分析实战从一行日志读出完整故事2.1 开启GC日志的正确姿势JDK1.8参数在JDK1.8里GC日志参数和后来的JDK11、JDK17风格完全不同别用后者的UNIFIED LOGGING方式套在1.8上。常用的一组命令如下-XX:PrintGCDetails -XX:PrintGCDateStamps -XX:PrintHeapAtGC -Xloggc:/data/logs/gc.log简单解释一下这组参数的作用。PrintGCDetails会打印详细的GC前后堆内存变化这是必开的PrintGCDateStamps会在每条GC日志前加上可读的日期时间方便跟业务报障时间对齐PrintHeapAtGC会在GC前后各打印一次堆内存快照信息量最大但日志文件会长一些Xloggc指定GC日志输出路径注意它一旦指定GC日志就不再打到stdout而是写到文件里这是一个很多人会突然发现“控制台没有GC日志了”的原因。如果还想额外带上进程启动的耗时可以用-XX:PrintGCTimeStamps它会在GC日志里输出从JVM启动到当前的秒数。这两者不冲突可以同时开。我自己的习惯是同时开DateStamps和TimeStamps因为有时候要对比启动时长和GC间隔秒数比日期更好用。需要特别提醒的是JDK1.8的GC日志没有自动清理机制。如果不做外部处理gc.log会一直膨胀时间长了可以撑出几个GB。有两种常见解法外部用logrotate定期切分或者借助JVM参数里的-XX:UseGCLogFileRotation配合-XX:NumberOfGCLogs和-XX:GCLogFileSize做滚动。后者比较简单比如-Xloggc:/data/logs/gc.log -XX:UseGCLogFileRotation -XX:NumberOfGCLogs5 -XX:GCLogFileSize20M这组参数表示日志滚动保留5个文件每个文件最多20M。不过在JDK1.8里这个滚动方案有两个小毛病一是滚动时可能会丢失少量日志二是文件名后缀会带日期。我一般建议对核心服务既要滚动也要把GC日志独立放在一个磁盘空间充足的分区别和业务日志挤在一起。2.2 逐字段拆解一次Minor GC日志下面是一次真实的Minor GC日志字段已脱敏我用默认PSPO组合跑出来的2024-07-15T10:32:15.1230800: 382.456: [GC (Allocation Failure) [PSYoungGen: 655360K-87372K(761856K)] 1048576K-475848K(1992192K), 0.0380010 secs] [Times: user0.04 sys0.00, real0.04 secs]第一次看这行日志可以按顺序拆成六块。第一块是时间戳2024-07-15T10:32:15.1230800这是PrintGCDateStamps输出的带时区的时间。后面跟的382.456是JVM启动秒数也就是说这个GC发生在JVM启动约6分22秒之后。第二块是GC类型标记[GC (Allocation Failure) [PSYoungGen: ...]]。这里的GC表示一次Minor GC并不代表系统停顿非常严重。Allocation Failure是触发原因前面说了就是分配新对象时Eden区空间不够。第三块是PSYoungGen内部变化655360K-87372K(761856K)。箭头左边是GC前新生代已用内存右边是GC后新生代已用内存括号里是新生代总容量。新生代总容量761856K不是固定的Parallel Scavenge会根据运行情况做动态调整这跟-XX:UseAdaptiveSizePolicy有关系。如果你希望手工固定可以用-XX:SurvivorRatio和-Xmn来显式配置但默认自适应调整也不是坏事。第四块是整堆变化1048576K-475848K(1992192K)这就是新生代老年代合计的已用空间和总量。GC后整堆还有475MB这是正常现象因为存活对象总要留在某个地方。第五块是耗时0.0380010 secs大约38毫秒。第六块是[Times: user0.04 sys0.00, real0.04 secs]user是CPU用户态耗时sys是内核态耗时real是实际墙钟时间。在多线程GC时real通常会小于user因为多个GC线程并行处理。这一行日志能告诉我们什么如果它频繁出现而且每次GC后新生代占用都基本持平说明新生代对象分配速率很高但绝大多数存活不下来这就是典型的“新生代吞吐高没有内存泄漏”的信号。如果GC后新生代已用从87372K慢慢爬升到两三百M就得怀疑是不是有对象一直在Survivor区来回存活导致动态晋升过快。2.3 Full GC日志与CMS/G1日志特征Full GC日志比Minor GC要沉重得多。在默认PSPO下一次Full GC日志往往长这样2024-07-15T11:20:03.7890800: 1081.233: [Full GC (System.gc()) [PSYoungGen: 0K-0K(761856K)] [ParOldGen: 1258291K-1256683K(1398272K)] 1258291K-6683K(1992192K), [Metaspace: 11823K-11823K(1056768K)], 0.8726090 secs]注意这里有个很扎眼的现象老年代从1258291K变成1256683K只释放了1.6M左右而且Full GC之后老年代几乎没降。触发原因是System.gc()说明有代码显式调用了垃圾收集。这种情况在JDK1.8下要额外小心因为System.gc()在默认参数下会直接触发Full GC不是建议性调用。遇到这种日志第一反应是去代码里查谁在调System.gc()最常见的情境是某些框架清理缓存、堆外内存管理、或者有人写测试代码时随手加了一句。在启用CMS的情况下日志结构会完全不同。你会看到大量带CMS阶段的日志比如2024-07-15T10:40:00.1110800: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1398272K(1398272K)] ... 2024-07-15T10:40:00.2110800: [CMS-concurrent-mark-start] 2024-07-15T10:40:00.5230800: [CMS-concurrent-mark: 0.312/0.312 secs] 2024-07-15T10:40:00.5230800: [CMS-concurrent-preclean-start] ...CMS的Initial Mark和Remark阶段会造成STWStop The World但是通常比Full GC短很多中间Concurrent Mark阶段应用线程跟GC线程是并发跑的所以整体用户体验要平滑一些。有没有坑当然有CMS最经典的问题就是Concurrent Mode Failure并发清理的速度跟不上老年代增长CMS被迫退化到Full GC一次停顿可能几百毫秒甚至一秒以上。这个问题会在日志里明确打印“Concurrent Mode Failure”字样看到就该立刻关注老年代增长曲线。G1在JDK1.8上的日志风格又不一样典型特征是带“pause”字样比如[GC pause (G1 Evacuation Pause) (young) (initial-mark) 512M-200M(2048M), 0.0234321 secs]G1把停顿分为Young-Only和Mixed两种重点看“Mixed”停顿那是清理老年代对象的阶段。这篇博文以JDK1.8默认PS为主CMS/G1日志细节不展开太多但你要有能力“认出”它们别在日志里看到ParOldGen就以为系统出错。3. 思维导图式记忆框架GC知识体系化3.1 以思维导图形式整理核心节点给出一份文字版思维导图方便大家当索引用。把所有关键节点列成树状结构你可能需要根据自己习惯增减。JVM GC 知识框架 ├── 1. 内存区域 │ ├── 线程私有虚拟机栈、本地方法栈、程序计数器 │ └── 线程共享堆、方法区JDK8中为Metaspace │ ├── 堆新生代EdenSurvivor×2、老年代 │ └── Metaspace类元数据默认无固定上限 ├── 2. 分代与分配 │ ├── 新对象优先Eden │ ├── 大对象直接进老年代PretenureSizeThreshold │ ├── Survivor动态年龄判定 │ └── Minor GC / Major GC / Full GC 概念 ├── 3. HotSpot收集器 │ ├── 新生代Serial / ParNew / Parallel Scavenge │ ├── 老年代Serial Old / Parallel Old / CMS │ └── 全局G1Region化 ├── 4. 关键参数 │ ├── -Xms / -Xmx 堆初始和最大 │ ├── -Xmn 新生代大小 │ ├── -XX:NewRatio 老年代与新生代比例 │ ├── -XX:SurvivorRatio Eden与Survivor比例 │ ├── -XX:MaxTenuringThreshold 晋升年龄 │ ├── -XX:PrintGCDetails / PrintGCDateStamps / PrintHeapAtGC │ └── -XX:UseGCLogFileRotation 日志滚动 ├── 5. GC日志字段 │ ├── 触发原因 Allocation Failure / System.gc / Concurrent Mode Failure │ ├── GC类型 Minor GC / Full GC / CMS阶段 / G1撤离停顿 │ ├── 内存变化 区域名 前-后(容量) │ ├── 耗时 用户态/内核态/墙钟时间 │ └── Metaspace 单独一行 ├── 6. 指标观察 │ ├── 吞吐量 业务时间 /业务时间GC时间 │ ├── 停顿时间 单次GC的real耗时 │ ├── GC频率 适合用jstat观察趋势 │ └── 晋升情况 老年代增长曲线 └── 7. 调优手段 ├── 调整堆大小 ├── 调整新生代大小 ├── 更换收集器CMS/G1 ├── 降低Full GC频率 └── 代码层面减少短命大对象、避免System.gc这张思维导图是我整理给自己的并不追求覆盖全部参数但把“内存结构-收集器-日志字段-调优”串成一条主线。初学者可以照着这个框架去逐项展开有经验的人也可以拿它来检查自己是否在某个分支上有缺口比如“我熟悉CMS但不知道Metaspace日志怎么看”这类盲区。3.2 如何把GC日志分析变成性能调优的输入日志是给人看的不只是用来事后追责。GC日志真正的价值在于它能告诉你系统的内存行为是否健康进而给你调优方向。在JDK1.8默认PSPO下我习惯先用三个维度去评估再决定要不要动手。第一个维度是GC频率。记一下每分钟Minor GC次数和Full GC次数。如果Minor GC每秒都好几次说明新生代容量相对于对象分配速率太小。更优解往往是调大-Xmn给新生代更多空间或者干脆调大整个堆。但如果对象分配速率本身就高光调堆也只是延缓现象需要从业务代码减少临时对象数量。第二个维度是停顿耗时。单次Minor GC一般都在几十毫秒以内超过100ms就要警惕。单次Full GC如果超过300ms基本已经会对RT敏感业务产生可感知影响。停顿时间高低跟GC线程数、对象数量、GC算法都有关系必要时可以显示指定-XX:ParallelGCThreads但不要盲目调大线程数线程太多反而引起竞争。第三个维度是晋升情况。通过前后对比老年代占用如果老年代每次Full GC前都逼近容量上限说明晋升速率太快可能有大量长生命周期对象或者Survivor空间配置不合理。此时单纯增大老年代只会把Full GC往后挪真正的问题是对象本身寿命长应该考虑是否为这些对象设计了正确的容器大小甚至重构缓存策略。GC日志分析不该是救火工具而应该是日常监控。拿到几天前的gc.log把Full GC次数和业务发布、流量高峰对齐很多内存问题是可以提前发现的。比如“发布新版本后老年代增长斜率明显变大”这就是一个非常典型的回归信号甚至不需要看业务日志就能定位到大致时间点。4. 常见问题与排查技巧实录4.1 GC日志时间与系统时间不一致这个问题踩过的人很多。JDK1.8里PrintGCDateStamps输出的是JVM打印日志那一刻从操作系统取到的时间而操作系统时间一旦被NTP校准或人工调整GC日志里的时间会突然跳变。如果发现某一天的GC日志时间对不上业务报障时间先别怀疑GC日志参数先看看系统时间和时区。另外PrintGCTimeStamps输出的是JVM启动后的秒数这个值是单调递增的不受系统时间调整影响。所以在做时间对比时我经常优先看JVM启动秒数。比如业务日志记录的时间是10:32:15对应GC日志里的382.456秒反过来就能计算出启动时间。一旦系统时间被改过日期时间戳会乱但秒数不会骗人。排查技巧在JVM启动参数里加上-XX:PrintGCTimeStamps和业务日志中的相对时间配合使用。如果业务日志有自带的启动秒数做一次换算就能把GC和请求的时间对齐。这个方法在大量历史日志需要复盘时特别好用。4.2 GC日志文件过大与滚动策略GC日志能撑出多大完全看业务的分配压力和配置的详细程度。开了PrintHeapAtGC之后单次GC日志长度会明显变长如果一天几千次GC一个文件几个GB不是玩笑。前面提到过UseGCLogFileRotation这在JDK1.8里是官方支持的滚动方案。要注意的是JDK1.8的滚动日志文件命名有坑当文件滚动时老文件会在文件名后自动追加.0、.1这样的后缀但如果你同时开了PrintGCDateStamps控制台输出与文件输出混排时可能导致日志记录丢失。在一些极端情况下还会出现“滚动文件数量超过NumberOGCLogs后旧日志被删除但新日志没写进去”的怪问题重启应用后会发现gc.log缺失一截。我个人的实践是核心服务把GC日志放在独立目录用外部logrotate按天或按大小切分保留最近7天。这样即使JVM滚动方案有问题外部系统也能兜底。如果有容器或云原生环境直接把GC日志输出到标准输出然后由日志采集系统统一采集也是一个可靠的方向。4.3 GC日志缺失或未生成的具体排查你明明加了-Xloggc参数但发现gc.log里没内容或者压根没生成文件。这种情况按下面顺序排查基本都能定位。第一步看启动命令有没有生效。用ps -ef | grep java确认进程完整启动参数好多时候改完脚本忘了重启或者脚本里有两份JVM_OPTS后一份覆盖了前一份。第二步看权限。JVM进程启动用户对日志目录有没有写权限目录是否存在。如果目录不存在JVM一般不会自动创建而是直接报错或悄悄跳过。你可以先手动mkdir -p让目录存在再启动。第三步看是否被容器日志重定向。在Docker或K8s中如果Xloggc指向的是容器内路径而容器重启后文件就被清掉要注意挂载卷是否覆盖了路径。这种情况表面上是“没GC日志”实际上是“日志写进了另一个临时文件系统”。第四步用jcmd验证jcmd PID GC.rotate_log这个命令在JDK1.8里可以手动触发GC日志滚动。如果命令返回正常说明JVM的GC日志模块是活的。如果返回Unknown command说明JVM启动时可能没有开启对应的日志打印参数。4.4 一组实战调优案例模拟这里用一个模拟场景演示日志分析思路。假设你有一个后台数据处理应用堆设置是-Xms2g -Xmx2g新生代默认。没有显式指定收集器也就是PSPO。打开gc.log发现每隔一分钟就有一次Full GC每次Full GC耗时接近800ms老年代回收前后从1.5G降到1.2G但很快又涨回去。再往上看Minor GC记录发现新生代每次GC后Survivor占用从几十M缓慢爬到几百M而且对象晋升年龄往往在2左右就有一批进入老年代。这个模式说明什么Survivor空间过小动态年龄判定提前触发对象过早晋升到老年代老年代空间被迅速填满导致Full GC频繁。重点不是老年代不够大而是晋升年龄太低。针对这种情况可以考虑把-Xmn调大让新生代拥有更大内存同时用-XX:MaxTenuringThreshold调整晋升年龄或者用-XX:SurvivorRatio8给Survivor更合理空间。于是做两步调优把-Xms和-Xmx保持2g不变但-Xmn从默认调整到1g同时SurvivorRatio设为8。之后再观察日志Minor GC频率下降晋升到老年代的对象减少Full GC从一分钟一次变成几小时一次。整个过程没有改业务代码纯粹通过Log Mining定位到晋升策略异常。这里有个原则必须强调调优不要一次改一堆参数逐项验证效果才能知道哪个参数真正起作用。模拟场景里我同时改了-Xmn和SurvivorRatio虽然结果不错但如果效果不好定位就比较麻烦。遇到线上服务更稳妥的做法是先只调-Xmn观察一天再动SurvivorRatio。4.5 辅助命令jstat与GC日志搭配使用GC日志是事后分析jstat是实时观察两者结合判断效率会高很多。常用的jstat命令如下jstat -gc PID 1000 5这表示每隔1000毫秒输出一次GC统计共输出5次。各列的含义不再逐一展开但关键关注S0C、S1C、EC、OC这几个容量列以及YGC、FGC、GCT这几个累计值。一个实用技巧是观察FGCFull GC次数是否持续增长结合GCT看累计停顿时间。如果FGC在某个时间点突然跳动立刻去回看那一时间段的GC日志定位触发原因比盲猜要精准得多。jstat配合jmap或jcmd还可以查看类加载和堆转储信息。不过本篇主题是GC日志这些辅助工具点到为止。我的经验是把jstat定时采集结果也存下来例如借助监控系统每5秒采样一次持续几天就能做GC趋势曲线。趋势线比单条日志信息量大多了尤其能发现“老年代容量每周缓慢上涨”这种早期泄漏特征。结尾真要说GC日志分析有什么诀窍我觉得就四个字养成习惯。很多内存问题不是一出事就知道的而是潜伏几周甚至一个月才爆发出来。如果应用一上线就把完整GC日志打开同时配好滚动和采集你会比别人多出一大截“历史视野”。等到线上出问题时翻日志定位原因比临时加参数重启快得多。一个小技巧收尾在JDK1.8下排查GC问题如果发现某一段日志里Full GC的“System.gc()”字样反复出现别急着调堆参数先用jstack抓一下线程栈看看是谁在调用System.gc。有时候是框架自动触发的有时候是代码里一行“好心”注释掉的测试语句找到源头比调整堆结构更省力。把GC日志当成一个常开的体检仪而不是一台救火车的警铃这份功夫绝对值得下。 
长河君 · 2026/10/14 20:59:55 · 阅读 1.2k JVM垃圾收集器与GC日志分析实战：从HotSpot到JDK1.8调优
做Java后端这几年每逢应用发布前被问最多的问题之一就是JVM堆内存怎么设垃圾收集器用哪个其实很多时候答案早就在GC日志里躺着只是没几个人肯耐心去看。JVM的垃圾收集器、GC日志分析、HotSpot、JDK1.8这四个关键词凑在一起基本就是一次线上诊断的完整闭环。这篇文章不打算把规范文档复述一遍而是想从HotSpot在JDK1.8环境下的真实行为出发把“有哪些收集器、它们分别在什么场景下干活、日志里每一行都说了什么、怎么看日志发现问题”这条线彻底捋顺最后给一份可以直接照着背的GC思维导图结构。不管你是刚接手线上服务的新人还是已经有几年经验但一直靠经验猜配置的老手这轮内容应该都能对得上。1. JVM垃圾收集器全景从分代模型到HotSpot实现1.1 为什么JDK1.8默认组合是PSParallelOld很多人一开始接触垃圾收集器的时候都会被一堆名字砸晕Serial、ParNew、Parallel Scavenge、CMS、G1还有一堆Old。但如果把视角拉回到JDK1.8这个具体版本会发现默认组合其实很固定新生代用Parallel Scavenge老年代用Parallel Old。这也是Oracle JDK和OpenJDK在8u系列里长期保持的默认策略。这里首先要理解分代模型的出发点。HotSpot把堆分为新生代和老年代目的是让不同生命周期的对象走不同的回收路径。绝大多数对象“朝生夕灭”在新生代就能被清理掉没必要把它们挪到老年代再花大代价整理。新生代内部又分成Eden区和两个Survivor区默认比例是8:1:1。这个比例我见过不少项目改过但说实话大多数业务场景默认值就够了乱改反而会让对象在Survivor之间来回拷贝或者提前晋升。那为什么默认不是CMS更不是G1而是Parallel Scavenge Parallel Old因为JDK1.8的默认面向的是“吞吐量优先”场景。Parallel系列的核心理念是让垃圾收集线程和应用线程并行执行尽可能让CPU花更多时间在业务上而不是频繁停顿。用官方的话说它关注的是“通过调整停顿时间上限来间接控制吞吐量”但实际上PS系列更偏重吞吐量最大化。对大多数无状态服务、批量计算任务、内部管理系统来说这种组合最省心。这里有个容易踩的认知误区很多人觉得CMS才是默认因为网上文章提到CMS多实际上那个时代CMS常见于低延迟场景需要手动指定。如果你在启动命令里什么都没加JDK1.8跑起来的收集器就是PSPO。所以看GC日志时看到PSCON和ParOld时不要慌那不是异常也不是配了什么怪东西那就是默认组合的名字。1.2 七大收集器核心对比与选型逻辑要真正看懂GC日志至少得先把HotSpot在JDK1.8里能用的收集器记个大概。我把它们整理成一个粗线条的对比表重点不是参数而是“它们关心什么”。收集器分代线程模式主要目标典型场景Serial新生代单线程简单、低内存开销客户端应用、小堆、单核ParNew新生代多线程并行配合CMS服务端新生代并行回收Parallel Scavenge新生代多线程并行吞吐量优先后台任务、批量计算Serial Old老年代单线程兜底、CMS失败后备小堆、串行环境Parallel Old老年代多线程并行吞吐量优先配合Parallel ScavengeCMS老年代并发标记清除低延迟交互型服务、响应敏感G1不分代逻辑上Region多线程并发可预测停顿大堆、JDK8后期调优主流这张表里有一个关键点CMS是标记-清除所以会产生碎片而Parallel Old是标记-整理会移动对象。碎片的影响在日志里不会直接显示但会导致老年代明明还有大量空闲空间却没办法给大对象分配连续区域最后触发Full GC。这是CMS被嫌弃的核心理由之一。选型逻辑其实不复杂。如果你的应用是Web接口、实时性要求高、单次请求响应时间重要那CMS或JDK8下的G1通常更合适。如果你的应用是离线计算、吞吐量要求高、偶尔一次停顿可以接受那默认的PSPO就是好搭档。最怕的是“不知道自家默认是什么却按网上CMS调优文章把参数抄一遍”那样日志看不懂问题也照不出来。1.3 一个容易被忽略的点收集器与内存分配策略的关系垃圾收集器不是独立工作的它跟对象分配策略耦合很深。很多GC日志看似奇怪的现象根源其实在分配策略上而不在收集器本身。HotSpot的对象分配顺序大致是这样新对象优先在Eden区分配Eden区空间不足时触发Minor GC。如果一个对象体积太大超过了“大对象直接进入老年代”的阈值就会直接进老年代。这个阈值可以通过-XX:PretenureSizeThreshold设置但需要注意它只对Serial和ParNew生效对Parallel Scavenge并不直接生效。很多人在网上看到“通过这个参数避免大对象频繁在新生代拷贝”结果发现没效果就是因为默认收集器是Parallel Scavenge该参数不生效。除了大对象还有一个动态年龄判定。对象在Survivor区每熬过一次Minor GC年龄加一默认累积到15岁进入老年代。同时HotSpot还有一个动态机制如果Survivor区中同一年龄的对象大小总和超过Survivor空间的一半那么年龄大于等于这些对象的对象直接晋升老年代。这个机制在日志里不会打印但会导致某些对象比预期更早进入老年代进而影响Full GC频率。明白了分配策略再去看GC日志里的“Allocation Failure”就有另一个层次的理解。Allocation Failure是触发Minor GC最常见的GC Cause解释为“我准备分配新对象但Eden区空间实在不够了”。它不是一个错误而是一个常规事件。你要是把日志里的Allocation Failure当成异常去查大概率会空手而归。2. GC日志分析实战从一行日志读出完整故事2.1 开启GC日志的正确姿势JDK1.8参数在JDK1.8里GC日志参数和后来的JDK11、JDK17风格完全不同别用后者的UNIFIED LOGGING方式套在1.8上。常用的一组命令如下-XX:PrintGCDetails -XX:PrintGCDateStamps -XX:PrintHeapAtGC -Xloggc:/data/logs/gc.log简单解释一下这组参数的作用。PrintGCDetails会打印详细的GC前后堆内存变化这是必开的PrintGCDateStamps会在每条GC日志前加上可读的日期时间方便跟业务报障时间对齐PrintHeapAtGC会在GC前后各打印一次堆内存快照信息量最大但日志文件会长一些Xloggc指定GC日志输出路径注意它一旦指定GC日志就不再打到stdout而是写到文件里这是一个很多人会突然发现“控制台没有GC日志了”的原因。如果还想额外带上进程启动的耗时可以用-XX:PrintGCTimeStamps它会在GC日志里输出从JVM启动到当前的秒数。这两者不冲突可以同时开。我自己的习惯是同时开DateStamps和TimeStamps因为有时候要对比启动时长和GC间隔秒数比日期更好用。需要特别提醒的是JDK1.8的GC日志没有自动清理机制。如果不做外部处理gc.log会一直膨胀时间长了可以撑出几个GB。有两种常见解法外部用logrotate定期切分或者借助JVM参数里的-XX:UseGCLogFileRotation配合-XX:NumberOfGCLogs和-XX:GCLogFileSize做滚动。后者比较简单比如-Xloggc:/data/logs/gc.log -XX:UseGCLogFileRotation -XX:NumberOfGCLogs5 -XX:GCLogFileSize20M这组参数表示日志滚动保留5个文件每个文件最多20M。不过在JDK1.8里这个滚动方案有两个小毛病一是滚动时可能会丢失少量日志二是文件名后缀会带日期。我一般建议对核心服务既要滚动也要把GC日志独立放在一个磁盘空间充足的分区别和业务日志挤在一起。2.2 逐字段拆解一次Minor GC日志下面是一次真实的Minor GC日志字段已脱敏我用默认PSPO组合跑出来的2024-07-15T10:32:15.1230800: 382.456: [GC (Allocation Failure) [PSYoungGen: 655360K-87372K(761856K)] 1048576K-475848K(1992192K), 0.0380010 secs] [Times: user0.04 sys0.00, real0.04 secs]第一次看这行日志可以按顺序拆成六块。第一块是时间戳2024-07-15T10:32:15.1230800这是PrintGCDateStamps输出的带时区的时间。后面跟的382.456是JVM启动秒数也就是说这个GC发生在JVM启动约6分22秒之后。第二块是GC类型标记[GC (Allocation Failure) [PSYoungGen: ...]]。这里的GC表示一次Minor GC并不代表系统停顿非常严重。Allocation Failure是触发原因前面说了就是分配新对象时Eden区空间不够。第三块是PSYoungGen内部变化655360K-87372K(761856K)。箭头左边是GC前新生代已用内存右边是GC后新生代已用内存括号里是新生代总容量。新生代总容量761856K不是固定的Parallel Scavenge会根据运行情况做动态调整这跟-XX:UseAdaptiveSizePolicy有关系。如果你希望手工固定可以用-XX:SurvivorRatio和-Xmn来显式配置但默认自适应调整也不是坏事。第四块是整堆变化1048576K-475848K(1992192K)这就是新生代老年代合计的已用空间和总量。GC后整堆还有475MB这是正常现象因为存活对象总要留在某个地方。第五块是耗时0.0380010 secs大约38毫秒。第六块是[Times: user0.04 sys0.00, real0.04 secs]user是CPU用户态耗时sys是内核态耗时real是实际墙钟时间。在多线程GC时real通常会小于user因为多个GC线程并行处理。这一行日志能告诉我们什么如果它频繁出现而且每次GC后新生代占用都基本持平说明新生代对象分配速率很高但绝大多数存活不下来这就是典型的“新生代吞吐高没有内存泄漏”的信号。如果GC后新生代已用从87372K慢慢爬升到两三百M就得怀疑是不是有对象一直在Survivor区来回存活导致动态晋升过快。2.3 Full GC日志与CMS/G1日志特征Full GC日志比Minor GC要沉重得多。在默认PSPO下一次Full GC日志往往长这样2024-07-15T11:20:03.7890800: 1081.233: [Full GC (System.gc()) [PSYoungGen: 0K-0K(761856K)] [ParOldGen: 1258291K-1256683K(1398272K)] 1258291K-6683K(1992192K), [Metaspace: 11823K-11823K(1056768K)], 0.8726090 secs]注意这里有个很扎眼的现象老年代从1258291K变成1256683K只释放了1.6M左右而且Full GC之后老年代几乎没降。触发原因是System.gc()说明有代码显式调用了垃圾收集。这种情况在JDK1.8下要额外小心因为System.gc()在默认参数下会直接触发Full GC不是建议性调用。遇到这种日志第一反应是去代码里查谁在调System.gc()最常见的情境是某些框架清理缓存、堆外内存管理、或者有人写测试代码时随手加了一句。在启用CMS的情况下日志结构会完全不同。你会看到大量带CMS阶段的日志比如2024-07-15T10:40:00.1110800: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1398272K(1398272K)] ... 2024-07-15T10:40:00.2110800: [CMS-concurrent-mark-start] 2024-07-15T10:40:00.5230800: [CMS-concurrent-mark: 0.312/0.312 secs] 2024-07-15T10:40:00.5230800: [CMS-concurrent-preclean-start] ...CMS的Initial Mark和Remark阶段会造成STWStop The World但是通常比Full GC短很多中间Concurrent Mark阶段应用线程跟GC线程是并发跑的所以整体用户体验要平滑一些。有没有坑当然有CMS最经典的问题就是Concurrent Mode Failure并发清理的速度跟不上老年代增长CMS被迫退化到Full GC一次停顿可能几百毫秒甚至一秒以上。这个问题会在日志里明确打印“Concurrent Mode Failure”字样看到就该立刻关注老年代增长曲线。G1在JDK1.8上的日志风格又不一样典型特征是带“pause”字样比如[GC pause (G1 Evacuation Pause) (young) (initial-mark) 512M-200M(2048M), 0.0234321 secs]G1把停顿分为Young-Only和Mixed两种重点看“Mixed”停顿那是清理老年代对象的阶段。这篇博文以JDK1.8默认PS为主CMS/G1日志细节不展开太多但你要有能力“认出”它们别在日志里看到ParOldGen就以为系统出错。3. 思维导图式记忆框架GC知识体系化3.1 以思维导图形式整理核心节点给出一份文字版思维导图方便大家当索引用。把所有关键节点列成树状结构你可能需要根据自己习惯增减。JVM GC 知识框架 ├── 1. 内存区域 │ ├── 线程私有虚拟机栈、本地方法栈、程序计数器 │ └── 线程共享堆、方法区JDK8中为Metaspace │ ├── 堆新生代EdenSurvivor×2、老年代 │ └── Metaspace类元数据默认无固定上限 ├── 2. 分代与分配 │ ├── 新对象优先Eden │ ├── 大对象直接进老年代PretenureSizeThreshold │ ├── Survivor动态年龄判定 │ └── Minor GC / Major GC / Full GC 概念 ├── 3. HotSpot收集器 │ ├── 新生代Serial / ParNew / Parallel Scavenge │ ├── 老年代Serial Old / Parallel Old / CMS │ └── 全局G1Region化 ├── 4. 关键参数 │ ├── -Xms / -Xmx 堆初始和最大 │ ├── -Xmn 新生代大小 │ ├── -XX:NewRatio 老年代与新生代比例 │ ├── -XX:SurvivorRatio Eden与Survivor比例 │ ├── -XX:MaxTenuringThreshold 晋升年龄 │ ├── -XX:PrintGCDetails / PrintGCDateStamps / PrintHeapAtGC │ └── -XX:UseGCLogFileRotation 日志滚动 ├── 5. GC日志字段 │ ├── 触发原因 Allocation Failure / System.gc / Concurrent Mode Failure │ ├── GC类型 Minor GC / Full GC / CMS阶段 / G1撤离停顿 │ ├── 内存变化 区域名 前-后(容量) │ ├── 耗时 用户态/内核态/墙钟时间 │ └── Metaspace 单独一行 ├── 6. 指标观察 │ ├── 吞吐量 业务时间 /业务时间GC时间 │ ├── 停顿时间 单次GC的real耗时 │ ├── GC频率 适合用jstat观察趋势 │ └── 晋升情况 老年代增长曲线 └── 7. 调优手段 ├── 调整堆大小 ├── 调整新生代大小 ├── 更换收集器CMS/G1 ├── 降低Full GC频率 └── 代码层面减少短命大对象、避免System.gc这张思维导图是我整理给自己的并不追求覆盖全部参数但把“内存结构-收集器-日志字段-调优”串成一条主线。初学者可以照着这个框架去逐项展开有经验的人也可以拿它来检查自己是否在某个分支上有缺口比如“我熟悉CMS但不知道Metaspace日志怎么看”这类盲区。3.2 如何把GC日志分析变成性能调优的输入日志是给人看的不只是用来事后追责。GC日志真正的价值在于它能告诉你系统的内存行为是否健康进而给你调优方向。在JDK1.8默认PSPO下我习惯先用三个维度去评估再决定要不要动手。第一个维度是GC频率。记一下每分钟Minor GC次数和Full GC次数。如果Minor GC每秒都好几次说明新生代容量相对于对象分配速率太小。更优解往往是调大-Xmn给新生代更多空间或者干脆调大整个堆。但如果对象分配速率本身就高光调堆也只是延缓现象需要从业务代码减少临时对象数量。第二个维度是停顿耗时。单次Minor GC一般都在几十毫秒以内超过100ms就要警惕。单次Full GC如果超过300ms基本已经会对RT敏感业务产生可感知影响。停顿时间高低跟GC线程数、对象数量、GC算法都有关系必要时可以显示指定-XX:ParallelGCThreads但不要盲目调大线程数线程太多反而引起竞争。第三个维度是晋升情况。通过前后对比老年代占用如果老年代每次Full GC前都逼近容量上限说明晋升速率太快可能有大量长生命周期对象或者Survivor空间配置不合理。此时单纯增大老年代只会把Full GC往后挪真正的问题是对象本身寿命长应该考虑是否为这些对象设计了正确的容器大小甚至重构缓存策略。GC日志分析不该是救火工具而应该是日常监控。拿到几天前的gc.log把Full GC次数和业务发布、流量高峰对齐很多内存问题是可以提前发现的。比如“发布新版本后老年代增长斜率明显变大”这就是一个非常典型的回归信号甚至不需要看业务日志就能定位到大致时间点。4. 常见问题与排查技巧实录4.1 GC日志时间与系统时间不一致这个问题踩过的人很多。JDK1.8里PrintGCDateStamps输出的是JVM打印日志那一刻从操作系统取到的时间而操作系统时间一旦被NTP校准或人工调整GC日志里的时间会突然跳变。如果发现某一天的GC日志时间对不上业务报障时间先别怀疑GC日志参数先看看系统时间和时区。另外PrintGCTimeStamps输出的是JVM启动后的秒数这个值是单调递增的不受系统时间调整影响。所以在做时间对比时我经常优先看JVM启动秒数。比如业务日志记录的时间是10:32:15对应GC日志里的382.456秒反过来就能计算出启动时间。一旦系统时间被改过日期时间戳会乱但秒数不会骗人。排查技巧在JVM启动参数里加上-XX:PrintGCTimeStamps和业务日志中的相对时间配合使用。如果业务日志有自带的启动秒数做一次换算就能把GC和请求的时间对齐。这个方法在大量历史日志需要复盘时特别好用。4.2 GC日志文件过大与滚动策略GC日志能撑出多大完全看业务的分配压力和配置的详细程度。开了PrintHeapAtGC之后单次GC日志长度会明显变长如果一天几千次GC一个文件几个GB不是玩笑。前面提到过UseGCLogFileRotation这在JDK1.8里是官方支持的滚动方案。要注意的是JDK1.8的滚动日志文件命名有坑当文件滚动时老文件会在文件名后自动追加.0、.1这样的后缀但如果你同时开了PrintGCDateStamps控制台输出与文件输出混排时可能导致日志记录丢失。在一些极端情况下还会出现“滚动文件数量超过NumberOGCLogs后旧日志被删除但新日志没写进去”的怪问题重启应用后会发现gc.log缺失一截。我个人的实践是核心服务把GC日志放在独立目录用外部logrotate按天或按大小切分保留最近7天。这样即使JVM滚动方案有问题外部系统也能兜底。如果有容器或云原生环境直接把GC日志输出到标准输出然后由日志采集系统统一采集也是一个可靠的方向。4.3 GC日志缺失或未生成的具体排查你明明加了-Xloggc参数但发现gc.log里没内容或者压根没生成文件。这种情况按下面顺序排查基本都能定位。第一步看启动命令有没有生效。用ps -ef | grep java确认进程完整启动参数好多时候改完脚本忘了重启或者脚本里有两份JVM_OPTS后一份覆盖了前一份。第二步看权限。JVM进程启动用户对日志目录有没有写权限目录是否存在。如果目录不存在JVM一般不会自动创建而是直接报错或悄悄跳过。你可以先手动mkdir -p让目录存在再启动。第三步看是否被容器日志重定向。在Docker或K8s中如果Xloggc指向的是容器内路径而容器重启后文件就被清掉要注意挂载卷是否覆盖了路径。这种情况表面上是“没GC日志”实际上是“日志写进了另一个临时文件系统”。第四步用jcmd验证jcmd PID GC.rotate_log这个命令在JDK1.8里可以手动触发GC日志滚动。如果命令返回正常说明JVM的GC日志模块是活的。如果返回Unknown command说明JVM启动时可能没有开启对应的日志打印参数。4.4 一组实战调优案例模拟这里用一个模拟场景演示日志分析思路。假设你有一个后台数据处理应用堆设置是-Xms2g -Xmx2g新生代默认。没有显式指定收集器也就是PSPO。打开gc.log发现每隔一分钟就有一次Full GC每次Full GC耗时接近800ms老年代回收前后从1.5G降到1.2G但很快又涨回去。再往上看Minor GC记录发现新生代每次GC后Survivor占用从几十M缓慢爬到几百M而且对象晋升年龄往往在2左右就有一批进入老年代。这个模式说明什么Survivor空间过小动态年龄判定提前触发对象过早晋升到老年代老年代空间被迅速填满导致Full GC频繁。重点不是老年代不够大而是晋升年龄太低。针对这种情况可以考虑把-Xmn调大让新生代拥有更大内存同时用-XX:MaxTenuringThreshold调整晋升年龄或者用-XX:SurvivorRatio8给Survivor更合理空间。于是做两步调优把-Xms和-Xmx保持2g不变但-Xmn从默认调整到1g同时SurvivorRatio设为8。之后再观察日志Minor GC频率下降晋升到老年代的对象减少Full GC从一分钟一次变成几小时一次。整个过程没有改业务代码纯粹通过Log Mining定位到晋升策略异常。这里有个原则必须强调调优不要一次改一堆参数逐项验证效果才能知道哪个参数真正起作用。模拟场景里我同时改了-Xmn和SurvivorRatio虽然结果不错但如果效果不好定位就比较麻烦。遇到线上服务更稳妥的做法是先只调-Xmn观察一天再动SurvivorRatio。4.5 辅助命令jstat与GC日志搭配使用GC日志是事后分析jstat是实时观察两者结合判断效率会高很多。常用的jstat命令如下jstat -gc PID 1000 5这表示每隔1000毫秒输出一次GC统计共输出5次。各列的含义不再逐一展开但关键关注S0C、S1C、EC、OC这几个容量列以及YGC、FGC、GCT这几个累计值。一个实用技巧是观察FGCFull GC次数是否持续增长结合GCT看累计停顿时间。如果FGC在某个时间点突然跳动立刻去回看那一时间段的GC日志定位触发原因比盲猜要精准得多。jstat配合jmap或jcmd还可以查看类加载和堆转储信息。不过本篇主题是GC日志这些辅助工具点到为止。我的经验是把jstat定时采集结果也存下来例如借助监控系统每5秒采样一次持续几天就能做GC趋势曲线。趋势线比单条日志信息量大多了尤其能发现“老年代容量每周缓慢上涨”这种早期泄漏特征。结尾真要说GC日志分析有什么诀窍我觉得就四个字养成习惯。很多内存问题不是一出事就知道的而是潜伏几周甚至一个月才爆发出来。如果应用一上线就把完整GC日志打开同时配好滚动和采集你会比别人多出一大截“历史视野”。等到线上出问题时翻日志定位原因比临时加参数重启快得多。一个小技巧收尾在JDK1.8下排查GC问题如果发现某一段日志里Full GC的“System.gc()”字样反复出现别急着调堆参数先用jstack抓一下线程栈看看是谁在调用System.gc。有时候是框架自动触发的有时候是代码里一行“好心”注释掉的测试语句找到源头比调整堆结构更省力。把GC日志当成一个常开的体检仪而不是一台救火车的警铃这份功夫绝对值得下。