JVM 核心技术 —— 调优分析
1. GC 日志解读与分析 *
任务:
1)模拟一下OOM (测试使用的 GCLogAnalysis.class 是一个字节码文件,该文件在5秒内持续创建对象,并随机地将一些对象缓存起来,这部分对象无法被 GC 回收) 2)分别使用512m,1024m/1g,2048m/2g,4096m/4g,观察 GC 信息的不同
1.1 Parallel GC (young 区 和 old 区 都是并行 GC)
java -Xmx1g -Xms1g -XX:+UseParallelGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:-UseAdaptiveSizePolicy GCLogAnalysis > parallel.log
JVM启动参数如上所示,将 XMX、XMS 分别替换为 256m、512m、1g、2g、4g 后的测试结果如下(gc日志可上传到 https://gceasy.io/ 进行分析):
GC类型 | 堆内存大小 | 创建对象数 | 总GC次数 | MinorGC次数 | MajorGC次数 | 总暂停时间(程序运行5s) | 暂停次数 | 平均每次暂停时间 | 单次最大暂停时间 | Avg creation rate | Avg promotion rate | 备注 |
---|---|---|---|---|---|---|---|---|---|---|---|---|
Parallel | 256m | – | 49 | 8 | 41 | – | – | 25.9 ms | 70.0 ms | – | – | OOM |
Parallel | 512m | 34291 | 85 | 14 | 71 | 3 sec 10 ms | 85 | 35.4 ms | 60 ms | 1.78 gb/sec | 97.12 mb/sec | |
Parallel | 1g | 59067 | 71 | 58 | 13 | 1 sec 470 ms | 71 | 20.7 ms | 50.0 ms | 3.05 gb/sec | 783.75 mb/sec | |
Parallel | 2g | 66637 | 36 | 33 | 3 | 1 sec 100 ms | 36 | 30.6 ms | 60.0 ms | 3.53 gb/sec | 727.12 mb/sec | |
Parallel | 4g | 67763 | 17 | 17 | 0 | 1 sec 310 ms | 17 | 77.1 ms | 440 ms | 3.86 gb/sec | 471.71 mb/sec |
总结:最大堆内存参数 Xmx 应该设置为一个较为合理的数值,当 Xmx 太小的时候,会发生 OOM ,当 Xmx 设置的太大的时候,尽管 Full GC 的次数减少了,但是平均每次 GC 暂停 (STW) 的时长却增加了,暂停时间过高对于高并发系统并不是一个好现象。
1.2 Serial GC (young 区和 old 区都是穿行 GC)
java -Xmx256m -Xms256m -XX:+UseSerialGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:-UseAdaptiveSizePolicy GCLogAnalysis > serial.log
JVM启动参数如上所示,将 XMX、XMS 分别替换为 256m、512m、1g、2g、4g 后的测试结果如下(gc日志可上传到 https://gceasy.io/ 进行分析):
GC类型 | 堆内存大小 | 创建对象数 | 总GC次数 | MinorGC次数 | MajorGC次数 | 总暂停时间(程序运行5s) | 暂停次数 | 平均每次暂停时间 | 单次最大暂停时间 | Avg creation rate | Avg promotion rate | 备注 |
---|---|---|---|---|---|---|---|---|---|---|---|---|
Serial | 256m | – | – | – | – | – | – | – | – | – | – | OOM |
Serial | 512m | 30262 | 61 | 10 | 51 | 3 sec 290 ms | 61 | 53.9 ms | 80.0 ms | 1.56 gb/sec | 79.67 mb/sec | |
Serial | 1g | 56056 | 52 | 42 | 10 | 1 sec 940 ms | 52 | 37.3 ms | 110 ms | 2.91 gb/sec | 616.5 mb/sec | |
Serial | 2g | 59321 | 28 | 26 | 2 | 1 sec 540 ms | 28 | 55.0 ms | 90.0 ms | 3.2 gb/sec | 657.12 mb/sec | |
Serial | 4g | 59870 | 14 | 14 | 0 | 1 sec 330 ms | 14 | 95.0 ms | 120 ms | 3.44 gb/sec | 470.33 mb/sec |
1.3 CMS GC(young 区使用 parnewGC(并行), old 区使用 CMSGC (并发))
java -Xmx1g -Xms1g -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:-UseAdaptiveSizePolicy GCLogAnalysis > cms.log
JVM启动参数如上所示,将 XMX、XMS 分别替换为 256m、512m、1g、2g、4g 后的测试结果如下(gc日志可上传到 https://gceasy.io/ 进行分析):
GC类型 | 堆内存大小 | 创建对象数 | 总GC次数 | MinorGC次数 | MajorGC次数 | 总暂停时间(程序运行5s) | 暂停次数 | 平均每次暂停时间 | 单次最大暂停时间 | Avg creation rate | Avg promotion rate | 备注 |
---|---|---|---|---|---|---|---|---|---|---|---|---|
CMS | 256m | – | – | – | – | – | – | – | – | – | – | OOM |
CMS | 512m | 29054 | 55 | 52 | 3 | 3 sec 340 ms | 138 | 24.2 ms | 100 ms | 1.35 gb/sec | 111.03 mb/sec | |
CMS | 1g | 57831 | 55 | 49 | 6 | 1 sec 730 ms | 79 | 21.9 ms | 80.0 ms | 2.01 gb/sec | 750.3 mb/sec | |
CMS | 2g | 61627 | 60 | 59 | 1 | 1 sec 790 ms | 67 | 26.7 ms | 60 ms | 2.96 gb/sec | 949.4 mb/sec | |
CMS | 4g | 56750 | 55 | 55 | 0 | 1 sec 790 ms | 57 | 31.4 ms | 50.0 ms | 2.88 gb/sec | 853.87 mb/sec |
1.4 G1 GC(Garbage First GC, 不再区分整块的 young 和 old , 而是将整个堆内存划分为 2048 个小块,根据使用情况确定每个块是 eden、survivor 还是 old)
java -Xmx1g -Xms1g -XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:-UseAdaptiveSizePolicy GCLogAnalysis > g1.log
JVM启动参数如上所示,将 XMX、XMS 分别替换为 256m、512m、1g、2g、4g 后的测试结果如下(gc日志可上传到 https://gceasy.io/ 进行分析):
GC类型 | 堆内存大小 | 创建对象数 | 总GC次数 | MinorGC次数 | MajorGC次数 | 总暂停时间(程序运行5s) | 暂停次数 | 平均每次暂停时间 | 单次最大暂停时间 | Avg creation rate | Avg promotion rate | 备注 |
---|---|---|---|---|---|---|---|---|---|---|---|---|
G1 | 256m | – | – | – | – | – | – | – | – | – | – | OOM |
G1 | 512m | 23724 | – | – | – | 3 sec 800 ms | 620 | 6.13 ms | 70.0 ms | 1.27 gb/sec | 252.21 mb/sec | |
G1 | 1g | 61016 | – | – | – | 1 sec 780 ms | 255 | 6.98 ms | 30.0 ms | 3.32 gb/sec | 243.85 mb/sec | |
G1 | 2g | 81051 | – | – | – | 1 sec 20 ms | 87 | 11.7 ms | 50.0 ms | 4.45 gb/sec | 102.36 mb/sec | |
G1 | 4g | 86676 | – | – | – | 830 ms | 30 | 27.7 ms | 60.0 ms | 4.73 gb/sec | 644.47 mb/sec |
总结: G1GC在大内存下效果非常好,吞吐量高,总暂停时间短,平均暂停时间短。
2. JVM 线程堆栈分析
JVM 内部线程主要分为以下几种:
• VM 线程:单例的VMThread 对象,负责执行VM 操作;
• 定时任务线程:单例的WatcherThread 对象, 模拟在VM 中执行定时操作的计时器中断;
• GC 线程:垃圾收集器中,用于支持并行和并发垃圾回收的线程;
• 编译器线程: 将字节码编译为本地机器代码;
• 信号分发线程:等待进程指示的信号,并将其分配给Java 级别的信号处理方法。
安全点:
-
- 方法代码中被植入的安全点检测入口;
-
- 线程处于安全点状态:线程暂停执行,这个时候线程栈不再发生改变;
-
- JVM 的安全点状态:所有线程都处于安全点状态。
JVM 支持多种方式来进行线程转储:
-
- JDK 工具, 包括: jstack 工具, jcmd 工具,jconsole,jvisualvm, Java Mission Control 等;
-
- Shell 命令或者系统控制台,比如Linux 的kill -3,Windows 的Ctrl + Break 等;
-
- JMX 技术, 主要是使用ThreadMxBean。
其他工具
可将 jstack 命令输出的日志上传到 https://fastthread.io/ 进行分析
3. 内存分析与相关工具*
一个Java 对象占用多少内存?
对象头和对象引用
在64位JVM 中,对象头占据的空间是 12 个字节(开启压缩指针,未开启压缩指针是 16 个字节),但是以8字节对齐,所以一个空类的实例至少占用 16 字节。在32位JVM 中,对象头占8个字节,以4的倍数对齐(32=4*8)。所以new 出来很多简单对象,甚至是newObject(),都会占用不少内容。关于对象头的理解,可查看https://www.zhihu.com/question/263335109
通常在32位 JVM,以及内存小于-Xmx32G 的64位 JVM 上(默认开启指针压缩),一个引用占的内存默认是4个字节。因此,64位 JVM 一般需要多消耗堆内存。
包装类型
比原生数据类型消耗的内存要多:
Integer:占用16字节(头部8+4=12,数据4字节),因为int 部分占4个字节。所以使用Integer 比原生类型 int 要多消耗300% 的内存。
Long:一般占用24个字节(头部8+4+数据8=20字节,再对齐),当然,对象的实际大小由底层平台的内存对齐确定,具体由特定 CPU 平台的 JVM 实现决定。看起来一个 Long 类型的对象,比起原生类型 long 多占用了8个字节(也多消耗200%)。
多维数组
在二维数组int[dim1][dim2] 中,每个嵌套的数组int[dim2] 都是一个单独的Object,会额外占用16字节的空间。当数组维度更大时,这种开销特别明显。int[128][2] 实例占用3600字节。而int[256] 实例则只占用1040字节。里面的有效存储空间是一样的,3600 比起1040多了246%的额外开销。在极端情况下,byte[256][1],额外开销的比例是19倍!
String
String 对象的空间随着内部字符数组的增长而增长。当然,String 类的对象有24个字节的额外开销。
对于10字符以内的非空String,增加的开销比起有效载荷(每个字符2字节+ 4 个字节的length),多占用了100% 到400% 的内存。
OutOfMemoryError: Java heap space
创建新的对象时,堆内存中的空间不足以存放新创建的对象产生的原因,很多时候就类似于将XXL 号的对象,往S 号的Java heap space 里面塞。其实清楚了原因,问题就很容易解决了:只要增加堆内存的大小,程序就能正常运行。
另外还有一些情况是由代码问题导致的:
• 超出预期的访问量/数据量:应用系统设计时,一般是有“容量” 定义的,部署这么多机器,用来处理一定流量的数据/业务。如果访问量突然飙升,超过预期的阈值,类似于时间坐标系中针尖形状的图谱。那么在峰值所在的时间段,程序很可能就会卡死、并触发java.lang.OutOfMemoryError: Java heap space 错误。
• 内存泄露(Memory leak):这也是一种经常出现的情形。由于代码中的某些隐蔽错误,导致系统占用的内存越来越多。如果某个方法/某段代码存在内存泄漏,每执行一次,就会(有更多的垃圾对象)占用更多的内存。随着运行时间的推移,泄漏的对象耗光了堆中的所有内存,那么java.lang.OutOfMemoryError: Java heap space 错误就爆发了。
OutOfMemoryError: PermGen space/OutOfMemoryError: Metaspace
java.lang.OutOfMemoryError: PermGen space 的主要原因,是加载到内存中的类数量太多或体积太大,超过了PermGen 区的大小。
解决办法:
增大PermGen/Metaspace
-XX:MaxPermSize=512m
-XX:MaxMetaspaceSize=512m
高版本JVM 也可以:
-XX:+CMSClassUnloadingEnabled
由于 JDK 8 以及以后的版本 Metaspace 的大小默认为无限大,这个问题不必特殊关注。但是,仍然推荐设置 Metaspace 的大小,从而更好地控制内存空间的使用。
OutOfMemoryError: Unable to create new native thread
java.lang.OutOfMemoryError: Unable to create new native thread 错误是程序创建的线程数量已达到上限值的异常信息。
解决思路:
- 调整系统参数ulimit -a,echo 120000 > /proc/sys/kernel/threads-max
-
降低 xss 等参数 (减少单个线程栈的大小,从而创建更多的线程)
-
调整代码,改变线程创建和使用方式
内存 Dump 分析工具
- Eclipse MAT
- jhat
4. JVM 分析调优经验*
4.1 高分配速率(High Allocation Rate)
分配速率(Allocation rate)表示单位时间内分配的内存量。通常使用 MB/sec 作为单位。上一次垃圾收集之后,与下一次GC开始之前的年轻代使用量,两者的差值除以时间,就是分配速率。
分配速率过高就会严重影响程序的性能,在JVM 中可能会导致巨大的GC 开销。
正常系统:分配速率较低 ≈ 回收速率 -> 健康
内存泄漏:分配速率持续大于回收速率 -> OOM
性能劣化:分配速率很高 ≈ 回收速率 -> 亚健康
4.2 2、过早提升(Premature Promotion)
提升速率(promotion rate)用于衡量单位时间内从年轻代提升到老年代的数据量。一般使用 MB/sec 作为单位, 和分配速率类似。
JVM 会将长时间存活的对象从年轻代提升到老年代。根据分代假设,可能存在一种情况,老年代中不仅有存活时间长的对象,,也可能有存活时间短的对象。这就是过早提升:对象存活时间还不够长的时候就被提升到了老年代。
Full GC 不是为频繁回收而设计的,但Full GC 现在也要清理这些生命短暂的对象,就会导致GC 暂停时间过长。这会严重影响系统的吞吐量。
和分配速率一样GC 之前和之后的年轻代使用量以及堆内存使用量。这样就可以通过差值算出老年代的使用量。
提升速率也会影响GC 暂停的频率。但分配速率主要影响minor GC,而提升速率则影响major GC 的频率。有大量的对象提升,自然很快将老年代填满。老年代填充的越快,则major GC 事件的频率就会越高。
一般来说过早提升的症状表现为以下形式:
- 短时间内频繁地执行full GC
- 每次full GC 后老年代的使用率都很低,在10-20%或以下
- 提升速率接近于分配速率
解决方案
解决这类问题,需要让年轻代存放得下暂存的数据,有两种简单的方法。
一是增加年轻代的大小,设置JVM 启动参数,类似这样:
-Xmx64m -XX:NewSize=32m,程序在执行时,Full GC 的次数自然会减少很多,只会对minor GC 的持续时间产生影响。
二是减少每次业务处理使用的内存数量,也能得到类似的结果。
至于选用哪个方案,要根据业务需求决定。但总体目标依然是一致的:让临时数据能够在年轻代存放得下。
5. JVM 疑难情况问题分析
1、查询业务日志,可以发现这类问题:请求压力大,波峰,遭遇降级,熔断等等, 基础服务、外部API 依赖出现故障。
2、查看系统资源和监控信息:
硬件信息、操作系统平台、系统架构;
排查CPU 负载、内存不足,磁盘使用量、硬件故障、磁盘分区用满、IO 等待、IO 密集、丢数据、并发竞争等情况;
排查网络:流量打满,响应超时,无响应,DNS 问题,网络抖动,防火墙问题,物理故障,网络参数调整、超时、连接数。
3、查看性能指标,包括实时监控、历史数据。可以发现假死,卡顿、响应变慢等现象;
排查数据库, 并发连接数、慢查询、索引、磁盘空间使用量、内存使用量、网络带宽、死锁、TPS、查询数据量、redo 日志、undo、binlog 日志、代理、工具BUG。可以考虑的优化包括: 集群、主备、只读实例、分片、分区;
可能还需要关注系统中使用的各类中间件。
4、排查系统日志, 比如重启、崩溃、Kill 。
5、APM,比如发现有些链路请求变慢等等。
6、排查应用系统
排查配置文件: 启动参数配置、Spring 配置、JVM 监控参数、数据库参数、Log 参数、内存问题,比如是否存在内存泄漏,内存溢出、批处理导致的内存放大等等;
GC 问题, 确定GC 算法,GC 总耗时、GC 最大暂停时间、分析GC 日志和监控指标: 内存分配速度,分代提升速度,内存使用率等数据,适当时修改内存配置;
排查线程, 理解线程状态、并发线程数,线程Dump,锁资源、锁等待,死锁;
排查代码, 比如安全漏洞、低效代码、算法优化、存储优化、架构调整、重构、解决业务代码BUG、第三方库、XSS、CORS、正则;
7、可以在性能测试中进行长期的压测和调优分析。
注:可以使用 Arthas 诊断分析工具进行分析。
- 本文固定链接: https://weiguangli.com/archives/597
- 转载请注明: lwg0452 于 Weiguang的博客 发表