记一次OOM查询处理过程
-
问题的爆出及分析排查现场
-
排查后的解决方案
-
项目的jvm参数
-
总结
一、问题的爆出及分析排查现场
服务偶尔会出现不可用的情况,导致出现time out,然后我迅速登录现场,直接查看当时的gc日志,不废话,直接上图
通过这个图可以发现在10点7分、8分的时候频繁Full GC,但是GC之后 年轻代,老年代并没有少。并且Full GC时长5s8多,造成stop-the-world5s8,因此应用程序会出现无影响。再贴一张图
通过这个可以看到内存慢慢的通过GC降下来了
根据这些信息基本可以断定,是由于什么操作导致内存飙升,并且都是一些大对象,就是由于这些大对象导致年轻代放不下,因此直接进入老年代(分配担保策略),而这个操作占用的内存大,因此触发了Full GC(jvm 触发Full GC的情况 https://blog.csdn.net/chenleixing/article/details/46706039/ ),再加上又比较耗时,因此频繁Full GC,因为对象一直被强引用着,导致无法被清除.
接下来立马使用jdk 自带的工具 jmap进行dump,然后使用jdk自带的jvisualvm进行dump文件分析,分析图如下:
通过这个图可以看到Xobj相关的对象大小占到内存的61%左右,由于我对于这个项目又比较熟悉,所以很快就能定位是由于操作Excel文件导致的.因为一看这个就知道是和xml解析相关的。
当然也可以通过分析工具来定位到比较具体的点的信息(这个留给读者来实操,复现现场,然后及时dump 堆内存进行分析,一定要在Xobj相关实例在可触达的情况下dump.找准时机)
当定位是和Excel相关时,紧接着看了下和excel相关的处理文件,发现文件都不大,最大的也就40万左右,7M而已,那么为什么会产生这么大的内存对象内,于是乎,就去百度,然后得到的结果大概是poi读取excel有两种模式,一种user model 另一种event mode, 而我使用的是user model 模式,这种模式使用的内存和cpu 较之 event model都要大很多。而我为了方便,又是将excel 文件全部读取然后进行处理。
二、排查后的解决方案
解决方案分两步走,一步是代码层面、一步是jvm参数方面
代码层面:读取excel文件使用event model 方式,并且每读取100行,便处理然后释放引用,这样便于被GC回收
jvm参数方面:之前年轻代是300M左右,而堆的总内存大小是4G,感觉年轻代的设置不太合理,因此调到800M,然后进行观察,观察后可进行适当的调整
三、项目的jvm参数
-XX:CICompilerCount=3 设置编译线程的数量。JVM在server模式下默认是2,在client模式下默认是1。如果使用分层编译的话,这个值会扩展到与CPU核数一样的值。
-XX:InitialHeapSize=4294967296 设置堆的初始值
-XX:InitialTenuringThreshold=5 设置初始的对象在新生代中最大存活次数
-XX:MaxHeapSize=4294967296 设置堆分配的最大值,单位字节
-XX:MaxNewSize=348913664 新生代占整个堆内存的最大值。从Java1.4开始, MaxNewSize成为 NewRatio的一个函数
-XX:MinHeapDeltaBytes=196608
-XX:OldPLABSize=16
-XX:OldSize=3946053632
-XX:+UseCompressedOops 可以压缩指针,起到节约内存占用的新参数。使用compressed pointers。这个参数默认在64bit的环境下默认启动,但是如果JVM的内存达到32G后,这个参数就会默认为不启动,因为32G内存后,压缩就没有多大必要了,要管理那么大的内存指针也需要很大的宽度了
-XX:SurvivorRatio=8 Eden与Survivor的占用比例。例如8表示,一个survivor区占用 1/8 的Eden内存,即1/10的新生代内存,为什么不是1/9? 因为我们的新生代有2个survivor,即S1和S22。所以survivor总共是占用新生代内存的 2/10,Eden与新生代的占比则为 8/10。
-XX:MaxMetaspaceSize=512M 这个参数用于限制Metaspace增长的上限,防止因为某些情况导致Metaspace无限的使用本地内存,影响到其他程序。在本机上该参数的默认值为4294967295B(大约4096MB)
-XX:+UseCompressedClassPointers
-XX:CompressedClassSpaceSize=512M 的调优只有当-XX:+UseCompressedClassPointers开启了才有效
-XX:MaxTenuringThreshold=5 设置对象在新生代中最大的存活次数,最大值15,并行回收机制默认为15,CMS默认为4
-------------------CMS相关参数-------------------
-XX:CMSInitiatingOccupancyFraction=70 使用cms作为垃圾回收使用70%后开始CMS收集
-------------------收集器设置-------------------
-XX:+UseConcMarkSweepGC
指 定在 Old Generation 使用 concurrent cmark sweep gc,gc thread 和 app thread 并行 ( 在 init-mark 和 remark 时 pause app thread). app pause 时间较短 , 适合交互性强的系统 , 如 web server
-XX:+UseParNewGC
设置年轻代为并行收集。可与CMS收集同时使用。JDK5.0以上,JVM会根据系统配置自行设置,所以无需再设置此值。
-------------------堆设置-------------------
-Xms4096m
指定 jvm 的最小 heap 大小 , 如 :-Xms=4g , 高并发应用, 建议和-Xmx一样, 防止因为内存收缩/突然增大带来的性能影响。
-Xmx4096m
指定 jvm 的最大 heap 大小
-XX:NewSize=348913664
设置年轻代大小
-XX:SurvivorRatio=8
指 定 New Generation 中 Eden Space 与一个 Survivor Space 的 heap size 比例 ,-XX:SurvivorRatio=8, 那么在总共 New Generation 为 10m 的情况下 ,Eden Space 为 8m
-------------------垃圾回收统计信息-------------------
-XX:+PrintGC
输出形式:[GC 118250K->113543K(130112K), 0.0094143 secs]
[Full GC 121376K->10414K(130112K), 0.0650971 secs]
-XX:+PrintGCDateStamps
GC发生的时间信息
-XX:+PrintGCDetails
输出形式:[GC [DefNew: 8614K->781K(9088K), 0.0123035 secs] 118250K->113543K(130112K), 0.0124633 secs]
[GC [DefNew: 8614K->8614K(9088K), 0.0000665 secs][Tenured: 112761K->10414K(121024K), 0.0433488 secs] 121376K->10414K(130112K), 0.0436268 secs]
-XX:+PrintGCTimeStamps
输出形式:11.851: [GC 98328K->93620K(130112K), 0.0082960 secs]
-Xloggc:logs/gc.log.201808142235
与上面几个配合使用,把相关日志信息记录到文件以便分析
-------------------3个设置滚动记录GC日志的参数 测试一下 -------------------
-XX:+UseGCLogFileRotation
打开或关闭GC日志滚动记录功能,要求必须设置 -Xloggc参数
-XX:NumberOfGCLogFiles=1
设置滚动日志文件的个数,必须大于1
日志文件命名策略是,<filename>.0, <filename>.1, ..., <filename>.n-1,其中n是该参数的值
-XX:GCLogFileSize=512M
设置滚动日志文件的大小,必须大于8k
当前写日志文件大小超过该参数值时,日志将写入下一个文件
四、总结
这个示例告诉我们,使用任何第三方jar,都需要进行严格的测试,确保不会对现有的系统造成伤害。开发人员需要对jvm进行了解,特别是GC这块,因为你new 的每一行代码都是和GC相关的,至少密不可分,知道的越多,了解的越清楚,才能保证写出好的 code ,有些坑不一定要踩