gc 日志是排查 java 内存问题的核心工具,通过分析日志可以了解堆内存使用模式、gc 频率、对象晋升规律等关键信息。以下是系统化的分析方法:
一、gc 日志基础配置
1. 启用详细 gc 日志
java -xx:+printgcdetails \ -xx:+printgcdatestamps \ -xx:+printheapatgc \ -xx:+printtenuringdistribution \ -xx:+printgcapplicationstoppedtime \ -xloggc:/var/log/gc.log \ -xx:+usegclogfilerotation \ -xx:numberofgclogfiles=5 \ -xx:gclogfilesize=20m \ -jar your-app.jar
2. 不同收集器的日志格式
g1 收集器:
[gc pause (g1 evacuation pause) (young), 0.0144227 secs] [parallel time: 13.0 ms, gc workers: 8] [code root fixup: 0.1 ms] [code root scanning: 0.1 ms] [object copy: 12.6 ms] [termination: 0.1 ms] [termination attempts: 1] [gc worker other: 0.1 ms] [gc worker total: 12.9 ms] [gc worker end: 422.5 ms] [code root fixup: 0.0 ms] [code root scanning: 0.0 ms] [clear ct: 0.2 ms] [other: 1.2 ms] [choose cset: 0.0 ms] [ref proc: 0.6 ms] [ref enq: 0.0 ms] [redirty cards: 0.1 ms] [humongous register: 0.0 ms] [humongous reclaim: 0.0 ms] [free cset: 0.0 ms] [eden: 24.0m(24.0m)->0.0b(20.0m) survivors: 0.0b->4.0m heap: 24.0m(256.0m)->20.4m(256.0m)] [times: user=0.09 sys=0.00, real=0.01 secs]
cms 收集器:
[gc (allocation failure) [psyounggen: 8192k->512k(9216k)] 8192k->6848k(19456k), 0.0034949 secs] [times: user=0.01 sys=0.00, real=0.00 secs] [full gc (metadata gc threshold) [psyounggen: 512k->0k(9216k)] [paroldgen: 6336k->6848k(10240k)] 6848k->6848k(19456k), [metaspace: 2560k->2560k(1056768k)], 0.0254310 secs] [times: user=0.09 sys=0.00, real=0.03 secs]
二、关键指标与分析维度
1. gc 频率与耗时
问题表现:频繁 gc 或单次 gc 时间过长。
日志特征:
[gc (allocation failure) 514m->488m(1024m), 0.0124612 secs]
分析工具:
# 使用grep统计gc次数和总耗时 grep "gc" gc.log | wc -l # minor gc次数 grep "full gc" gc.log | wc -l # full gc次数 # 计算平均gc耗时 awk '/gc.*secs/ {sum+=$nf} end {print "average gc time: " sum/nr " secs"}' gc.log
2. 堆内存使用趋势
问题表现:堆内存持续增长,接近上限。
日志特征:
[eden: 24.0m(24.0m)->0.0b(20.0m) survivors: 0.0b->4.0m heap: 24.0m(256.0m)->20.4m(256.0m)]
分析重点:
- eden 区:频繁 gc 后 eden 区是否能有效回收。
- 老年代:是否持续增长,是否触发 full gc。
3. 对象晋升情况
问题表现:对象过早晋升到老年代,导致老年代空间不足。
日志特征:
[tenuring distribution] age 1: 1310720 bytes, 1310720 total age 2: 655360 bytes, 1966080 total age 3: 327680 bytes, 2293760 total
分析工具:
# 提取对象年龄分布 grep -a 5 "tenuring distribution" gc.log
4. 垃圾收集器行为
问题表现:cms 并发模式失败、g1 mixed gc 频繁。
日志特征:
[gc (cms initial mark)] [1 cms-initial-mark: 4194304k(8388608k)] 4294901k(12582912k), 0.0024210 secs] [times: user=0.01 sys=0.00, real=0.00 secs]
三、常见内存问题与日志特征
问题 1:频繁 minor gc
日志特征:
[gc (allocation failure) 204800k->163840k(262144k), 0.0102400 secs]
可能原因:
- 新生代空间过小(-xmn 配置不合理)。
- 对象分配率过高(短时间内创建大量对象)。
解决方案:
# 增大新生代比例 java -xmn2g -xx:newratio=1 yourapp
问题 2:频繁 full gc
日志特征:
[full gc (metadata gc threshold) 524288k->512000k(1048576k), 0.5234120 secs]
可能原因:
- 老年代空间不足(大对象直接进入老年代)。
- 永久代 / 元空间溢出(类加载过多)。
- 内存泄漏(对象无法被回收)。
解决方案:
# 增大老年代空间 java -xms8g -xmx8g -xx:newratio=4 yourapp # 限制元空间大小 java -xx:metaspacesize=256m -xx:maxmetaspacesize=512m yourapp
问题 3:长时间 gc 停顿
日志特征:
[gc pause (g1 humongous allocation) (young), 1.2345678 secs]
可能原因:
- 使用 cms 收集器,并发阶段失败触发 full gc。
- 堆内存过大,导致标记和清理时间过长。
解决方案:
# 切换到g1或zgc收集器 java -xx:+useg1gc -xx:maxgcpausemillis=200 yourapp # 限制单次gc最大停顿时间 java -xx:+usezgc -xx:concgcthreads=8 yourapp
四、gc 日志分析工具
1. 命令行工具
# 统计gc频率和耗时 grep "gc" gc.log | awk '{print $4, $nf}' # 分析堆内存变化趋势 grep "\[heap\]" gc.log | awk '{print $6, $8}'
2. 可视化工具
gceasy(在线工具):
# 上传gc.log到https://gceasy.io/分析
gcviewer(本地工具):
java -jar gcviewer-1.36.jar gc.log
java mission control (jmc):
jmc & # 打开jmc,导入gc日志
3. 关键报告指标
- gc 频率:每分钟 minor gc 和 full gc 次数。
- gc 耗时占比:gc 时间占应用运行时间的百分比。
- 内存分配率:每秒分配的内存大小。
- 晋升率:每秒从新生代晋升到老年代的对象大小。
五、gc 日志分析流程
确认 gc 类型:区分 minor gc、major gc、full gc。
检查 gc 频率:是否过于频繁(如每分钟超过 10 次 full gc)。
分析内存趋势:
- 堆内存是否持续增长?
- 老年代增长速率是否异常?
检查 gc 耗时:单次 gc 时间是否过长(如超过 500ms)。
查看对象晋升:
- 是否有大量对象过早晋升?
- 晋升阈值是否合理(-xx:maxtenuringthreshold)?
定位 gc 原因:
- 是 allocation failure 还是 cms-concurrent-mode-failure?
结合堆转储分析:
# 在gc前后生成堆转储文件 jmap -dump:format=b,file=before_gc.hprof <pid> # 触发gc jcmd <pid> gc.run jmap -dump:format=b,file=after_gc.hprof <pid>
六、优化建议
合理分配堆内存:
# 根据应用特性调整新生代和老年代比例 java -xms4g -xmx4g -xmn2g yourapp
选择合适的收集器:
# 大内存应用推荐g1 java -xx:+useg1gc -xx:maxgcpausemillis=200 yourapp # 超低延迟场景推荐zgc java -xx:+usezgc -xx:concgcthreads=8 yourapp
优化对象生命周期:
- 减少长生命周期对象持有短生命周期对象的引用。
- 及时释放不再使用的资源(如集合、连接池)。
监控与预警:
- 设置 gc 频率和耗时的告警阈值。
- 定期分析 gc 日志,建立基线。
通过系统分析 gc 日志,可以精准定位内存泄漏、对象分配不合理、收集器选择不当等问题,从而优化 jvm 配置,提升应用性能。
总结
以上为个人经验,希望能给大家一个参考,也希望大家多多支持代码网。
发表评论