
第一步:3分钟拆解垃圾回收日志的核心指标
要分析日志,首先得知道怎么“生产”日志——很多人遇到性能问题了才想起看GC日志,结果发现根本没开启日志输出,这就像生病了才想起没做体检。我一般 在项目启动时就加上这些参数:-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
,前两个参数让日志包含详细信息和时间戳,第三个指定日志输出路径。你可别小看这一步,去年帮电商部排查一个秒杀系统卡顿问题时,他们就是没开PrintGCDateStamps
,导致无法对应卡顿时间点和GC事件,白白多花了2小时。
拿到日志后,先别盯着密密麻麻的文字看,我们先抓住3个核心指标:
日志里最常见的就是[GC]
和[Full GC]
,你可以简单理解为“小回收”(YGC,新生代回收)和“大回收”(FGC,老年代+新生代回收)。比如[GC (Allocation Failure) ...]
就是YGC,通常是新生代空间不够放新对象了;而[Full GC (System.gc()) ...]
可能是代码里显式调用了System.gc()
(这是个坑,后面调优会说)。
这里有个关键:YGC虽然频繁,但单次停顿短(正常在10-100ms);FGC单次停顿长(超过100ms就可能影响用户体验),所以日志里FGC的次数和耗时是你要重点盯的。我之前帮支付系统调优时,发现他们FGC每次要1.2秒,一天20次,这意味着每天有24秒用户付款时可能卡住,想想都后怕。
日志里“12345K->6789K(123456K)”这样的格式很常见,前面的“12345K”是GC前内存使用量,“6789K”是GC后使用量,括号里“123456K”是该区域总容量。比如YGC日志里“102400K->51200K(204800K)”,说明新生代总容量200M,GC前用了100M,回收后降到50M,回收了50M空间。
这里有个小技巧:你可以算一下“回收效率”=(GC前
日志末尾“0.0123450 secs”就是GC停顿时间,也就是系统“卡一下”的时间。Oracle的Java官方文档里提到过,对于Web应用,单次GC停顿超过200ms就可能被用户感知到卡顿(参考链接{rel=”nofollow”})。你可以拿个计算器,把一天内所有FGC停顿时间加起来,如果超过10秒,就得重点优化了。
为了让你更直观,我整理了一个“GC日志核心参数速查表”,你可以保存下来对照看:
参数格式 | 含义 | 正常范围 | 异常信号 |
---|---|---|---|
[GC (Allocation Failure)…] | 新生代回收(YGC) | 每天<1000次,耗时<50ms/次 | 每分钟>10次,耗时>100ms |
[Full GC…] | 全堆回收(FGC) | 每天<10次,耗时<200ms/次 | 每小时>1次,耗时>500ms |
X->Y(Z) | GC前后内存使用量(总容量) | Y/X>30%(回收效率) | Y/X<10%(内存浪费)或X接近Z(内存不足) |
0.0XX secs | GC停顿时间 | YGC<100ms,FGC<200ms | FGC>500ms,累计日停顿>10s |
除了手动看日志,你也可以用工具辅助分析。我常用的是GCViewer(免费开源),把gc.log文件拖进去,就能生成可视化图表,新生代/老年代内存变化、GC次数趋势一目了然。上次帮游戏项目调优,就是通过GCViewer发现每天凌晨3点有大量FGC,最后定位到是定时任务批量处理数据时创建了太多大对象,这个工具帮我省了至少半天时间。
第二步:从日志定位瓶颈并实战调优(附真实案例)
看懂指标后,下一步就是从日志里“揪出”问题,然后动手调优。这一步最关键的是“结合业务场景”——同样的GC日志,在秒杀系统和后台报表系统里,优化方向可能完全不同。我 了两个最常见的问题场景,你可以对号入座:
场景一:频繁YGC(新生代回收),单次停顿短但总卡顿
如果日志里YGC次数特别多(比如每分钟超过10次),但单次停顿只有20-30ms,你可能会想:单次停顿不长,应该没事吧?但用户实际体验可能是“系统有点卡,但说不上来哪里卡”——因为YGC虽然快,但频繁发生会让CPU一直在“回收-分配”循环里,业务线程被频繁打断。
去年帮一个社交APP调优时就遇到这个情况:他们的聊天服务YGC每30秒一次,单次25ms,看起来还行,但用户反馈“发消息偶尔要等半秒”。查日志发现,高峰期YGC甚至每10秒一次,一天下来有8000多次!
解决思路
:这类问题通常是新生代空间太小,或者对象创建太快。你可以试试这两个参数:
-Xmn512m
(新生代大小,默认堆内存的1/3),我当时把他们的新生代从256M调到512M,YGC间隔从30秒延长到90秒,次数减少60%。 -XX:+UseTLAB
,让每个线程在新生代有独立的分配区域,减少锁竞争,这个参数默认是开启的,但我发现有些老项目JVM配置里被关掉了,打开后YGC效率提升了15%。 场景二:FGC耗时过长,系统“卡死”几秒
这种情况最致命,日志里会看到[Full GC ... 1.234 secs]
,如果发生在支付、下单等核心流程,用户可能直接放弃操作。之前电商大促时,有个项目FGC每次1.8秒,刚好卡在抢购峰值期,导致瞬间订单量掉了30%,排查后发现是老年代内存不足,每次FGC都要“硬撑着”回收碎片。
定位技巧
:先看FGC前的内存使用量,比如日志里“[Full GC … 3890M->1200M(4096M)]”,说明老年代总容量4G,FGC前用了3.8G,几乎满了——这就是典型的“老年代空间不足”。这时候别着急调大内存,先看“是谁把老年代塞满了”:
jmap -histo:live
命令查看存活对象,按内存占用排序,我当时发现一个com.xxx.Message
对象占了2.5G,原来是消息队列消费异常,消息堆积在内存里没处理,改了消费逻辑后,老年代使用率降到50%,FGC耗时从1.8秒降到0.3秒。 jmap -dump:format=b,file=heap.hprof
导出堆 dump,用MAT工具分析引用链。我遇到过一个案例,是静态集合static List
忘了清理,一直往里塞数据,3天就撑满老年代,清理后FGC直接消失了。 调优参数参考
:如果确实是内存不够,这些参数可以试试(根据堆大小调整):
-XX:NewRatio=2
(新生代:老年代=1:2,堆内存12G的话,老年代8G) -XX:+UseZGC
),停顿时间能控制在10ms以内,我去年把一个核心服务从G1换成ZGC,FGC彻底消失了,不过ZGC需要JDK11+,如果是JDK8,用G1收集器-XX:+UseG1GC
也比默认的ParallelGC好。 避坑指南:这些“坑参数”别乱用
调优时千万别盲目抄网上的配置,我见过有人直接加-XX:+DisableExplicitGC
禁用System.gc()
,结果导致某些依赖显式GC的第三方组件内存泄漏;还有人把-Xms
和-Xmx
设成不一样(比如-Xms2G -Xmx4G
),导致堆内存动态扩容时触发FGC。记住:调优是“循序渐进”的,改一个参数,观察1-2天日志变化,再决定下一步,别想着“一步到位”。
最后给你留个小练习:找你项目的gc.log文件,用第一步教的方法,统计下今天YGC和FGC的次数、总停顿时间,然后对照表格看看有没有异常。如果发现问题,试试第二步的调优思路,遇到解决不了的,可以把日志片段发给我,我们一起分析。
你平时分析GC日志时,最头疼的是哪个问题?是看不懂参数,还是调优后没效果?可以在评论区告诉我,我后面专门写一篇针对性的解析!
开GC日志其实很简单,就是在启动Java程序的时候,多填几个JVM参数就行。我一般会推荐这三个参数一起用:-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
。你可能会问,为啥要这么多参数?其实每个都有讲究——PrintGCDetails
是让日志里能看到具体的内存变化、回收类型这些细节,没有它,日志就只有干巴巴的一句“GC发生了”,等于白看;PrintGCDateStamps
更关键,会给每条GC日志加上时间戳,比如2024-05-20T14:30:25.123+0800
,有了这个,你才能把日志里的GC事件和监控平台上的卡顿时间点对应起来。去年帮运维同事排查一个定时任务卡顿问题,他们就是没加这个参数,结果日志里只有“GC”,根本不知道是凌晨2点还是下午3点发生的,硬生生多花了1小时才对上时间线。
至于-Xloggc:./gc.log
,是指定日志输出到哪个文件,千万别用默认的控制台输出,不然日志混在业务日志里,找起来头都大。生产环境里我 你把路径写全,比如/var/log/app/gc.log
,再配个日志滚动——JDK9以后可以用-Xlog:gc:file=/var/log/app/gc.log:time,filecount=5,filesize=100m
,这样日志满100MB就自动切新文件,最多保留5个,不用担心占满磁盘。对了,如果你用的是JDK8及以前的版本,那PrintGCDateStamps
可能要换成PrintGCApplicationStoppedTime
才能看到更细的停顿时间,不过现在大部分项目都升级到JDK11+了,直接用前面那套参数就行。你下次部署项目的时候,记得检查下启动脚本里有没有这几行,别等出了问题才发现“哎?我没开GC日志啊!”,那就真的只能干着急了。
如何开启Java垃圾回收日志?
启动Java程序时添加JVM参数即可开启,推荐配置:-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
。其中PrintGCDetails
输出详细GC信息(如内存变化、耗时),PrintGCDateStamps
让日志包含时间戳(方便对应卡顿时间点),Xloggc
指定日志保存路径( 放在非临时目录,避免丢失)。生产环境 固定路径,方便后续分析。
日志中的[GC]和[Full GC]有什么区别?
简单说,[GC]
通常是“小回收”(YGC,新生代回收),主要清理新生代的短期对象,单次停顿短(一般10-100ms),但频率较高;[Full GC]
是“大回收”(全堆回收),会清理新生代+老年代,甚至永久代/元空间,单次停顿长(超过100ms可能影响用户体验),频率低但需重点关注。比如日志中[GC (Allocation Failure)]
是新生代空间不足触发的YGC,[Full GC (System.gc())]
可能是代码显式调用System.gc()
导致(不 这么做,会强制触发FGC)。
分析GC日志有哪些好用的工具?
推荐3类工具,覆盖不同场景:①本地分析工具:GCViewer(免费开源,拖入日志即可生成内存趋势图、GC次数统计,适合详细分析);②在线工具:GCEasy(上传日志自动生成报告,标红异常指标,新手友好);③命令行工具:JDK自带的jstat(实时查看GC状态,如jstat -gc 1000
每秒输出一次GC统计,适合快速排查)。实际工作中我常用GCViewer,能直观看到YGC/FGC的趋势变化,比纯看日志省时间。
调优时如何设置新生代和老年代的大小?
没有绝对标准,核心是“观察日志+匹配业务”。新生代(控制YGC频率):默认占堆内存的1/3,若系统频繁创建短期对象(如接口请求对象),可调大到1/2(通过-Xmn
参数,如-Xmn1g
),延长YGC间隔;老年代(控制FGC风险):默认占堆内存的2/3(通过-XX:NewRatio
控制,如-XX:NewRatio=2
表示新生代:老年代=1:2),若有大对象(如批量处理的列表), 预留更多空间(老年代占比不低于1/2)。调完后观察1-2天,若YGC间隔在30秒-5分钟、FGC每天少于10次,基本算合理配置。
GC日志太大,如何避免占满磁盘空间?
3个实用方法:①日志滚动(JDK9+支持,参数如-Xlog:gc:file=./gc.log:time,filecount=5,filesize=100m
,保留5个日志文件,每个最大100MB,满了自动覆盖旧文件);②定期归档(用Linux的logrotate工具,配置每天压缩日志并保留7天,避免长期占用空间);③按需输出(非调试时可简化日志,用-XX:+PrintGC
替代PrintGCDetails
,只输出关键GC事件)。注意保留至少3天的完整日志,方便对比性能变化(比如今天和昨天的FGC次数是否有异常)。