阿里二面:用过GC日志可视化工具进行JVM调优吗?

大家好,我是不才陈某~

上周知识星球的小伙伴面了阿里,在二面中被问到GC日志分析,感觉回答的不是很好,过来找我复盘,大致听了他的回答,虽然回答出了部分,但是没抓到重点。

GC日志分析算是JVM调优中比较难的部分,今天这篇文章就来聊聊如何利用JDK现有的命令并且借助可视化工具如何去分析GC日志。

JVM调优实践

JVM实践调优主要步骤

默认的策略是最普用,但不是最佳的。

第一步:监控分析GC日志

第二步:判断JVM问题:

  • 如果各项参数设置合理,系统没有超时日志出现,GC频率不高,GC耗时不高,那么没有必要进行GC优化;如果GC时间超过1-3秒,或者频繁GC,则必须优化。

第三步:确定调优目标

第四步:调整参数

  • 调优一般是从满足程序的内存使用需求开始,之后是时间延迟要求,最后才是吞吐量要求,要基于这个步骤来不断优化,每一个步骤都是进行下一步的基础,不可逆行之。

第五步:对比调优前后差距

第六步:重复:1 、 2 、 3 、 4 、 5 步骤

  • 找到最佳JVM参数设置

第七步:应用JVM到应用服务器:

  • 找到最合适的参数,将这些参数应用到所有服务器,并进行后续跟踪。

以上,就是我们进行jvm调优得一些步骤了。

那我们就从第一步开始喽!!!^_^

分析GC日志

初始参数设置

机器环境:

指标参数
机器CPU 12核,内存16GB
集群规模单机
seqb_web版本1.0
数据库4核 16G

Jvm调优典型参数设置;

  1. -Xms堆内存的最小值:

  2. 默认情况下,当堆中可用内存小于40%时,堆内存会开始增加,一直增加到-Xmx的大小。

  3. -Xmx堆内存的最大值: 默认值是总内存/64(且小于1G)

  4. 默认情况下,当堆中可用内存大于70%时,堆内存会开始减少,一直减小到-Xms的大小;

  5. -Xmn新生代内存的最大值:

  • 包括Eden区和两个Survivor区的总和

  • 配置写法如:-Xmn1024k,-Xmn1024m,-Xmn1g

  1. -Xss每个线程的栈内存:

  • 默认1M,一般来说是不需要改。线程栈越小意味着可以创建的线程数越多

整个堆的大小 = 年轻代大小 + 年老代大小,堆的大小不包含元空间大小,如果增大了年轻代,年老代相应就会减小,官方默认的配置为年老代大小/年轻代大小=2/1左右;关注公众号:码猿技术专栏,回复关键词 1111 获取阿里内部java性能调优手册

建议在开发测试环境可以用Xms和Xmx分别设置最小值最大值,但是在线上生产环境,Xms和Xmx设置的值必须一样,防止抖动;

这里比较重要喔,一般我们都是将Xms和Xmx的值设置为一样的!!!

1509b6ff27833cd89c052eddc4f743a7.jpeg
比较重要喔

JVM调优设置合大小堆内存空间,既不能太大,也不能太小。那么应该设置为多少呢?

默认的配置是否存在性能瓶颈。关注公众号:码猿技术专栏,回复关键词 1111 获取阿里内部java性能调优手册;如果想要确定JVM性能问题瓶颈,需要进一步分析GC日志

  1. -XX:+PrintGCDetails 开启GC日志创建更详细的GC日志 ,默认情况下,GC日志是关闭的

  2. -XX:+PrintGCTimeStamps,-XX:+PrintGCDateStamps 开启GC时间提示

  • 开启时间便于我们更精确地判断几次GC操作之间的时两个参数的区别

  • 时间戳是相对于 0 (依据JVM启动的时间)的值,而日期戳(date stamp)是实际的日期字符串

  • 由于日期戳需要进行格式化,所以它的效率可能会受轻微的影响,不过这种操作并不频繁,它造成的影响也很难被我们感知。

-XX:+PrintHeapAtGC 打印堆的GC日志

-Xloggc:./logs/gc.log 指定GC日志路径

这里,我们是在window下面进行测试,idea配置如下:

3dae3c62d5401492df07a8c554916c00.jpeg
idea配置
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:E:/logs/gc-default.log

这样就会在e盘下logs文件夹下面,生成gc-default.log日志

3585402aaf355513f652b13ecddf585d.jpeg
gc-default.log

GC日志解读

Young GC 日志含义

2022-08-05T13:45:23.336+0800: 4.866: [GC (Metadata GC Threshold) [PSYoungGen: 136353K->20975K(405504K)] 160049K->48437K(720384K), 0.0092260 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]

这里的内容,我们一个一个解析:

2022-08-05T13:45:23.336+0800: 本次GC发生时间
4.866: 举例启动应用的时间
[GC【表示GC的类型,youngGC】 (Metadata GC Threshold) 元空间超阈值
[PSYoungGen: 136353K->20975K(405504K年轻代总空间)] 160049K->48437K(720384K)整堆), 0.0092260 secs本次垃圾回收耗时]
[Times: user=0.00本次GC消耗CPU的时间 sys=0.02系统暂停时间, real=0.02 secs实际应用暂停时间]

这里的解析,应该很详细了吧,还有谁看不懂的呢?

1ebd80a0e916615ecdd7473a75a5ed92.jpeg
有谁看不懂

FullGC 日志含义

2022-08-05T20:24:47.815+0800: 6.955: [Full GC (Metadata GC Threshold) [PSYoungGen: 701K->0K(72704K)] [ParOldGen: 38678K->35960K(175104K)] 39380K->35960K(247808K), [Metaspace: 56706K->56706K(1099776K)], 0.1921975 secs] [Times: user=1.03 sys=0.00, real=0.19 secs]

这里的内容,我们也是一个一个解析:

2022-08-05T20:24:47.815+0800:
6.955: 刚启动服务就Full GC【整堆回收!!】

[Full GC (Metadata GC Threshold) Metaspace空间超限!
[PSYoungGen: 701K->0K(72704K)] 年轻代没有回收空间
[ParOldGen: 38678K->35960K(175104K)] 39380K->35960K(247808K), 老年代也没有到阈值,整堆更没有到阈值
[Metaspace: 56706K->56706K(1099776K)], 0.1921975 secs]
[Times: user=1.03本次GC消耗CPU的时间 sys=0.00系统暂停时间, real=0.19 secs实际应用暂停时间]

看到这里,有些哥们就会说,这么看,也太恶心了吧,密密麻麻的日志,看着头疼!!!

那么接下来我们来学一个GC日志可视化工具

GC日志可视化分析

分析GC日志,就必须让GC日志输出到一个文件中,然后使用GC日志分析工具(gceasy.io:https://gceasy.io/) 进行分析

4c9fd2f43720c8104c5a5e5725c5ed55.jpeg
GC日志可视化分析

这里分析完之后,可以下载分析报告

e7e4836d7aca2596df4dacafed50251e.jpeg
下载分析报告

JVM内存占用情况

62537789471cb6df5ce93619a5dc2ad7.jpeg
JVM内存占用情况
Generation【区域】Allocated【最大值】Peak【占用峰值】
Young Generation【年轻代】74.5 mb74.47 mb
Old Generation【老年轻代】171 mb95.62 mb
Meta Space【元空间】1.05 gb55.38 mb
Young + Old + Meta space【整体】1.3 gb212.64 mb

关键性能指标

dd8862ea745ce1b43da1314c969ba6b1.jpeg
关键性能指标

1 、吞吐量:百分比越高表明GC开销越低。这个指标反映了JVM的吞吐量。

  • Throughput:97.043%

2 、GC 延迟:Latency

  • Avg Pause GC Time:7.80 ms 平均GC暂停时间

  • Max Pause GC Time:190 ms 最大GC暂停时间

GC 可视化交互聚合结果

34cfd0c01a52a26a9426a53eea99ff01.jpeg
可视化交互聚合结果

由上图可以看到,发生了3次full gc

存在问题:一开始就发生了 3 次full gc , 很明显不太正常;

GC 统计

12e1004f40056a1f270a11abd1a21985.jpeg
GC 统计

GC Statistics:GC统计

由上图可以得到,发生gc的总次数,young gc,full gc的统计,gc 暂停时间统计。

GC原因

7d109a76bd48b644d241fe6d476f5cb0.jpeg
GC原因
原因次数平均时间最大时间总耗时
Metadata GC Threshold643.3 ms190 ms260 ms
Allocation Failure533.77 ms10.0 ms200 ms

这里对这些原因解析一下:

  1. Metadata GC Threshold:元空间超阈值

  2. Allocation Failure :年轻代空间不足

这里补充一个原因,本案例还没出现的:

  • Ergonomics:译文是“人体工程学”,GC中的Ergonomics含义是负责自动调解gc暂停时间和吞吐量之间平衡从而产生的GC。关注公众号:码猿技术专栏,回复关键词 1111 获取阿里内部java性能调优手册;目的是使得虚拟机性能更好的一种做法。

由此可见,通过可视化的工具,可以快速的帮我们分析GC的日志。我们得善于利用工具。

因为gc的日志文件,内容太多,都是密密麻麻的数字,文本。看得实在是头疼。

有了gc easy可视化工具,而且还是在线的,十分的方便。GC日志分析是免费的

由于jvm调优实践的分析,篇幅比较长,所以今天就先到这里,剩下的留着下次分享了。

来源:https://juejin.cn/post/7128377003224334373

最后说一句(别白嫖,求关注)

陈某每一篇文章都是精心输出,如果这篇文章对你有所帮助,或者有所启发的话,帮忙点赞、在看、转发、收藏,你的支持就是我坚持下去的最大动力!

另外陈某的知识星球开通了,公众号回复关键词:知识星球 获取限量30元优惠券加入,目前更新了Spring全家桶实战系列亿级数据分库分表实战DDD微服务实战专栏我要进大厂等....

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值