记录一次jvm问题：Survivor区非常小 | UseAdaptiveSizePolicy策略

记录一次jvm问题：Survivor区非常小 | UseAdaptiveSizePolicy策略

问题

• top命令 发下吗某java应用cpu占用率过高

• top -Hp 15436 查看15436对应的子线程

• printf %x 15570 输出子线程号的16进制格式

3cd2

• jstack -l 15436|grep 0x3cd2 -A 30 输出栈使用信息

发现每次执行的任务都不相同，并且存在线程池等字眼，推断可能是线程池中的线程

• 通过jstat命令打印了一下gc信息 jstat -gcutil

[root@iZ8vb9ulxm0o3bupiv9gsnZ ~]# jstat -gcutil 15436 1000# 每1秒打印一次S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   97.94   0.00  49.18  83.46  96.71  95.41 1774861 16215.557  1892  516.266 16731.8230.00  80.02  61.68  83.47  96.71  95.41 1774862 16215.569  1892  516.266 16731.83588.77   0.00  37.98  83.47  96.71  95.41 1774863 16215.576  1892  516.266 16731.8420.00  97.41  17.83  83.48  96.71  95.41 1774864 16215.585  1892  516.266 16731.85093.98   0.00  20.88  83.49  96.71  95.41 1774865 16215.593  1892  516.266 16731.85993.98   0.00  90.47  83.49  96.71  95.41 1774865 16215.593  1892  516.266 16731.8590.00  95.48  89.02  83.49  96.71  95.41 1774866 16215.603  1892  516.266 16731.86899.81   0.00  88.59  84.41  96.71  95.41 1774867 16215.618  1892  516.266 16731.8830.00  90.99  58.32  84.59  96.71  95.41 1774868 16215.627  1892  516.266 16731.89296.44   0.00  71.57  84.85  96.71  95.41 1774869 16215.638  1892  516.266 16731.9030.00  96.93  63.29  84.85  96.71  95.41 1774870 16215.648  1892  516.266 16731.91496.63   0.00  55.62  84.85  96.71  95.41 1774871 16215.656  1892  516.266 16731.9220.00  99.04  29.60  84.86  96.71  95.41 1774872 16215.665  1892  516.266 16731.931

发现每一秒进行一次Young gc，并且每次大约12ms

本来想在本地跑一下，指定一下参数来打印gc log，但是我懒，并且这个项目不好在本地跑，所以就又仔细分析了分析.

继续查看通过jstat输出

发现老年代的占用率增长的也很快，每1秒增加%0.01甚至%0.5的内存，拿1秒%0.01来算，增长1%就需要100秒，10%就是1000秒大概16分钟(实际上我发现比这个时间短得多)，然后我等了等直到快发生full gc的时候，打开了jstat命令

发现full gc花费了250ms,而老年代的内存占用比从99.89%降低到了33.24%

效率很高，正常情况下，老年代的对象都是经过多次gc，达到一定的gc年龄后才进入老年代的，其存活率应该很高，显然此时进入老年代的对象是不正常的。我们想到对象移动到老年代的条件除了对象达到一定年另外还会发生另外一种情况即创建的对象比较大，即使发生young gc，也无法将对象存储到新生代中，则将会对象直接移动到老年代中。

• 通过jmap -heap 命令查看堆内存的使用情况

[root@iZ8vb9ulxm0o3bupiv9gsnZ bin]# jmap -heap 15436
Attaching to process ID 15436, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.221-b11using thread-local object allocation.
Parallel GC with 4 thread(s)Heap Configuration:MinHeapFreeRatio         = 0MaxHeapFreeRatio         = 100MaxHeapSize              = 4164943872 (3972.0MB)NewSize                  = 87031808 (83.0MB)MaxNewSize               = 1388314624 (1324.0MB)OldSize                  = 175112192 (167.0MB)NewRatio                 = 2SurvivorRatio            = 8 #重点MetaspaceSize            = 21807104 (20.796875MB)CompressedClassSpaceSize = 1073741824 (1024.0MB)MaxMetaspaceSize         = 17592186044415 MBG1HeapRegionSize         = 0 (0.0MB)Heap Usage:
PS Young Generation
Eden Space:capacity = 1363148800 (1300.0MB) #重点used     = 1008727416 (961.997428894043MB)free     = 354421384 (338.00257110595703MB)73.99980222261868% used
From Space:capacity = 12582912 (12.0MB)#重点used     = 3111560 (2.9674148559570312MB)free     = 9471352 (9.032585144042969MB)24.72845713297526% used
To Space:capacity = 12582912 (12.0MB)#重点used     = 0 (0.0MB)free     = 12582912 (12.0MB)0.0% used
PS Old Generationcapacity = 855638016 (816.0MB)used     = 405909288 (387.10526275634766MB)free     = 449728728 (428.89473724365234MB)47.439370435826916% used59263 interned Strings occupying 6687152 bytes.

突然发现一个比较诡异的东西，Eden Space大小为1300MB,From Space和To Space仅仅只有12.0M，这就证明了刚才的猜测，当分配新的对象的时候因为新生代没有新的区域再去分配对象的时候发生的Young gc，但是显然即使发生young gc,因为Survivor区域大小实在是太小，依然无法存储young gc下存活下来的对象，则直接将其放入到了老年代，随着不断的发生Young gc,Surrvivor因为不能容纳活下来对象，则直接将其放到了老年代，随着老年代不断地增大，则发生了 full gc。

到了现在，我们已经得出了原因的一部分，还有两个重要问题没有发现

• 为什么young gc如此频繁，我们猜测我们的代码中发生了大量对象的创建
• 明明采用了默认的SurvivorRadio默认比，为什么survivor与eden的比值差的如此之大

我们先通过jmap -histo 查看堆中的实例

发现存在几个比较大的对象

User和BaseRoom，这显然不正常的，通过IDEA的搜索也没有找到是哪个地方出现了问题，最后只能dump出快照来

jmap -dump:format=b,file=jvm15436.hprof 15436

打开JProfiler分析dump文件

通过名称排序和包名快速找到User类，右键点击选中使用此对象

选择合并的支配引用，点击确定，进入引用情况页面

发现了引用链

DataEngine->List->BaseRoom->User

而DataEngine在项目是个比较特殊的存在，其

• 交给Spring管理的，但是是多例的
• 是消息队列中消息的一个处理类，每来自一条消息，都会利用Spring新建一个DataEngine对象，将收到的消息传入对象中，并将其放到线程池中处理
• DataEngine的确存在一个List保存的是BaseRoom列表
• list的初始化方式中，存在一种方式从redis中读取所有的baseRoom(非常多)，且此种初始化方式经常被调用

到这我们就大体知道DataEngine中为什么存在这么多BaseRoom了

• 消息非常之多，每秒处理的消息非常多，每个消息都会新创建一个DataEngine

• 每个DataEngine都会初始化BaseRoomList列表，获取大量的baseRoom

• 由于缓存是存在redis中的，因此每次获取的对象list都的不到重用，或者说每次都会新建大量的baseRoom对象

  ​ 这就是总是进行young gc的原因了。除了总是gc 的问题，我们之前说了，还有一个问题，就是Survivor与Eden大小差距悬殊的问题，其是导致总是full gc的一个原因。

  ​ 通过查阅资料，正常境况下java8 中jvm的SurvivorRatio为8即Eden 与Survivor的比为8：1 ，并且上面jmap -heap命令也输出了此配置的值，不应该出现如此大的差距。我只能求助百度谷歌，果然找到了答案。

  ​ java8中默认使用的年轻代垃圾回收器是Parallel Scavenge收集器， 又称为吞吐量优先收集器, 它的目标达到一个可控制的吞吐量 。而为了控制吞吐量，它默认使用了GC自适应策略，因此我们关闭这个策略开关就可以了。UseAdaptiveSizePolicy开关参数

  下面是Parallel Scavenge三个与自适应策略重要的参数，

  • 控制最大垃圾收集停顿时间的-XX:MaxGCPauseMillis参数
    MaxGCPauseMillis参数允许的值是一个大于0的毫秒数，收集器将尽力保证内存回收花费的时间不超过设定值。不过大家不要异想天开地认为如果把这个参数的值设置得稍小一点就能使得系统的垃圾收集速度变得更快，GC停顿时间缩短是以牺牲吞吐量和新生代空间来换取的：系统把新生代调小一些，收集300MB新生代肯定比收集500MB快吧，这也直接导致垃圾收集发生得更频繁一些，原来10秒收集一次、每次停顿100毫秒，现在变成5秒收集一次、每次停顿70毫秒。停顿时间的确在下降，但吞吐量也降下来了。

  • 直接设置吞吐量大小的 -XX:GCTimeRatio参数。
    GCTimeRatio参数的值应当是一个大于0小于100的整数，也就是垃圾收集时间占总时间的比率，相当于是吞吐量的倒数。如果把此参数设置为19，那允许的最大GC时间就占总时间的5%（即1 /（1+19）），默认值为99，就是允许最大1%（即1 /（1+99））的垃圾收集时间。

  • UseAdaptiveSizePolicy开关参数
    -XX:+UseAdaptiveSizePolicy是一个开关参数，当这个参数打开之后，就不需要手工指定新生代的大小（-Xmn）、Eden与Survivor区的比例（-XX:SurvivorRatio）、晋升老年代对象年龄（-XX:PretenureSizeThreshold）等细节参数了，虚拟机会根据当前系统的运行情况收集性能监控信息，动态调整这些参数以提供最合适的停顿时间或最大的吞吐量，这种调节方式称为GC自适应的调节策略（GC Ergonomics）。

  自适应调节策略也是Parallel Scavenge收集器与ParNew收集器的一个重要区别。

关闭AdaptiveSizePolicy的方式

• 开启：-XX:+UseAdaptiveSizePolicy

• 关闭：-XX:-UseAdaptiveSizePolicy

注意事项：

• 在 JDK 1.8 中，如果使用 CMS，无论 UseAdaptiveSizePolicy 如何设置，都会将 UseAdaptiveSizePolicy 设置为 false；不过不同版本的JDK存在差异；
• UseAdaptiveSizePolicy不要和SurvivorRatio参数显示设置搭配使用，一起使用会导致参数失效；
• 由于AdaptiveSizePolicy会动态调整 Eden、Survivor 的大小，**有些情况存在Survivor 被自动调为很小，比如十几MB甚至几MB的可能，这个时候YGC回收掉 Eden区后，还存活的对象进入Survivor 装不下，就会直接晋升到老年代，导致老年代占用空间逐渐增加，从而触发FULL GC，**如果一次FULL GC的耗时很长（比如到达几百毫秒），那么在要求高响应的系统就是不可取的。

对于面向外部的大流量、低延迟系统，不建议启用此参数，建议关闭该参数。

最终解决办法

1. -XX:-UseAdaptiveSizePolicy 关闭自适应策略，并适当增加新生代区域大小
2. 将DataEngine中的BaseRoomlist的获取改为通过id获取，而不是全部获取，限制list结果的大小
   • 或者不适用redis缓存，使用本地缓存(可使用LRU策略控制缓存的大小)
   • 或者改写DataEngine的方式，使其称为单例的（单例情况下尽量使用方法进行传参，避免线程安全问题）

总结

1. 现阶段大多数应用使用 JDK 1.8，其默认回收器是 Parallel Scavenge，并且默认开启了 AdaptiveSizePolicy。
2. AdaptiveSizePolicy 动态调整 Eden、Survivor 区的大小，存在将 Survivor 区调小的可能。当 Survivor 区被调小后，部分 YGC 后存活的对象直接进入老年代。老年代占用量逐渐上升从而触发 FGC，导致较长时间的 STW。
3. 建议使用 CMS 垃圾回收器，默认关闭 AdaptiveSizePolicy。
4. 建议在 JVM 参数中加上 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution，让 GC log 更加详细，方便定位问题。

常用命令

# 查看进程的资源使用情况
top
ps aux
## 查看指定进程的线程运行情况
top -Hp <pid>
ps -mp <pid> -o THREAD,tid,time
printf %x n #输出n的16进制jstack -l <pid>|grep <tid> -A 30 # pid是进程id,tid是线程id(0x+16进制数) -A 30是输出指定行后30行的数据
jstat -gc <pid> #查看gc情况，各代内存使用大小
jstat -gcutil <pid> #查看gc情况，各代内存占用比%
jmap -heap <pid> #查看jvm的配置以及各区域的使用情况
jmap -histo <pid>#查看堆中的各对象占用情况
jmap -histo:live <pid> #查看队中活跃对象的占用情况
jmap -dump:format=b,file=文件名 <pid> #dump 日志，文件名后缀可以是dump或者jps等

注意

• jmap -dump慎用： JVM会将整个heap的信息dump写入到一个文件，heap如果比较大的话，就会导致这个过程比较耗时，并且执行的过程中为了保证dump的信息是可靠的，所以会暂停应用。
• jmap -histo:live 慎用 这个命令执行，JVM会先触发gc，然后再统计信息。