大纲
1.如何对系统的OOM异常进行监控和报警
2.如何在JVM内存溢出时自动dump内存快照
3.Metaspace区域内存溢出时应如何解决(OutOfMemoryError: Metaspace)
4.JVM栈内存溢出时应如何解决(StackOverflowError)
5.JVM堆内存溢出时应该如何解决(OutOfMemoryError: Java heap space)
1.如何对系统的OOM异常进行监控和报警
(1)最佳的解决方案
(2)搭建系统监控体系的建议
(1)最佳的解决方案
最佳的OOM监控方案就是:建立一套监控平台,比如搭建Zabbix、Open-Falcon之类的监控平台。如果有监控平台,就可以接入系统异常的监控和报警,可以设置当系统出现OOM异常,就发送报警给对应的开发人员。这是中大型公司里最常用的一种方案。
监控平台一般会监控系统的如下几个层面:
一.机器资源(CPU、磁盘、内存、网络)的负载
二.JVM的GC频率和内存使用率
三.系统自身的业务指标
四.系统的异常报错
(2)搭建系统监控体系的建议
建议一:对机器指标进行监控
一.首先可以看到机器的资源负载情况
比如CPU负载,可以看到现在CPU目前的使用率有多高。比如磁盘IO负载,包括磁盘上发生了多少数据量的IO、一些IO耗时等。当然一般业务系统不会直接读写本地磁盘,最多就是写一些本地日志。但是一般业务系统也应该关注本地磁盘的使用量和剩余空间,因为有的系统可能会因为一些代码bug,导致一直往本地磁盘写东西。万一把磁盘空间写满了就麻烦了,磁盘满了也会导致系统无法运行。
二.其次可以看到机器的内存使用量
这个是从机器整体层面去看的,看看机器对内存使用的一些变化。当然内存这块,比较核心的还是JVM的监控,通过监控平台可以看到JVM各个内存区域的使用量的变化的。
三.还有一个比较关键的是JVM的FGC频率
一般会监控一段时间内的FGC次数,比如5分钟内发生了几次FGC。
四.最后就是机器上的网络负载
就是通过网络IO读写了多少数据、一些耗时等。
其实线上机器最容易出问题的主要有三方面:
一是CPU(必须要监控CPU的使用率),如果CPU负载过高(如长期超过90%)就报警。
二是内存(必须要监控内存的使用率),如果机器内存使用率超过一定阈值(如超90%)则可能内存不够。
三是JVM的FGC频率,假设5分钟内发生了10次FGC,那一定是频繁FGC了。
建议二:对业务指标进行监控
另外比较常见的就是对系统的业务指标进行监控。比如在系统每创建一个订单时就上报一次监控,然后监控系统会收集1分钟内的订单数量。这样就可以设定一个阈值,比如1分内要是订单数超过100就报警。因为订单过多可能涉及一些刷单行为,这就是业务指标监控。
建议三:对系统异常进行监控
最后就是对系统中所有的try catch异常报错,都接入报警。一旦发现有try catch异常,就上报到监控平台。然后监控平台就能通告这次异常,让相关负责人收到报警。比如一旦发现有OOM异常,就能马上通知相关开发人员。
2.如何在JVM内存溢出时自动dump内存快照
(1)解决OOM问题的一个初步思路
(2)在OOM时自动dump内存快照
(3)一份比较全面的JVM参数模板
(1)解决OOM问题的一个初步思路
如果发生OOM,则说明系统中某个区域的对象太多,塞满了那个区域。而且一定是无法回收掉区域中的那些对象,最终才会导致内存溢出。
要解决OOM,首先得知道是什么对象太多了,从而最终导致OOM的。所以必须有一份JVM发生OOM时的dump内存快照,只要有了那个dump内存快照,就可以用MAT工具分析什么对象太多了。
那么现在一个关键问题来了:到底怎么做才可以在JVM内存溢出时自动dump出一份内存快照呢?
(2)在OOM时自动dump内存快照
如果JVM发生OOM,JVM是不是完全来不及处理然后突然进程就没了?也就是JVM是不是非常突然的、自己都无法控制,就挂掉了?
其实不是的,JVM在发生OOM之前会尽可能进行GC腾出一些内存空间。如果GC后还是没有空间,放不下对象, 才会触发内存溢出。所以JVM自己对OOM情况的发生是完全有把控权的。
JVM知道什么时候会触发OOM,它是在无法放下对象的时候才会触发的。因此OOM的发生并不是突然内存太多,连JVM自己都没反应过来就崩溃。
JVM如果知道自己将要发生OOM了,那么此时完全可以让它做点事情。比如可以让JVM在OOM时dump一份内存快照,事后只要分析这个内存快照,就可以知道是哪些对象导致OOM的了。为此,需要在JVM的启动参数中加入如下参数:
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/usr/local/app/oom
第一个参数的意思是:在OOM时自动进行dump内存快照。第二个参数的意思是:把内存快照放到哪里。只要加入了这两个参数,可以事后再获取OOM时的内存快照进行分析。
(3)一份比较全面的JVM参数模板
-Xms4096M -Xmx4096M -Xmn3072M -Xss1M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFaction=92 -XX:+UseCMSCompactAtFullCollection -XX:CMSFullGCsBeforeCompaction=0 -XX:+CMSParallelInitialMarkEnabled -XX:+CMSScavengeBeforeRemark -XX:+DisableExplicitGC -XX:+PrintGCDetails -Xloggc:gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/usr/local/app/oom
这份JVM参数模板基本上涵盖了所有需要的一些参数。首先是各个内存区域的大小分配,这个需要精心调优的。其次是两种垃圾回收器的指定。接着是一些常规的CMS垃圾回收参数,可优化偶尔发生的FGC性能。最重要的,就是平时要打印出GC日志。GC日志可以配合jstat工具分析GC频率和性能的时候使用。jstat可分析出GC频率,但每次具体的GC情况则要结合GC日志来看。还有次重要的,就是发生OOM时能自动dump内存快照。这样即使突然发生OOM,且事后才知道,都可以分析当时的内存快照。
3.Metaspace区域内存溢出时应如何解决(OutOfMemoryError: Metaspace)
(1)解决思路
(2)示例代码
(3)分析GC日志
(4)分析内存快照
(1)解决思路
面对Metaspace区域内存溢出,思路如下:首先分析GC日志,然后再让JVM自动dump出内存快照。最后用MAT来分析这份内存快照,从内存快照里寻找OOM的原因。
(2)示例代码
public class Demo1 { public static void main(String[] args) { long counter = 0; while (true) { Enhancer enhancer = new Enhancer(); enhancer.setSuperclass(Car.class); enhancer.setUseCache(false); enhancer.setCallback(new MethodInterceptor() { @Override public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable { if (method.getName().equals("run")) { System.out.println("Check before run"); return methodProxy.invokeSuper(o, objects); } else { return methodProxy.invokeSuper(o, objects); } } }); Car car = (Car) enhancer.create(); car.run(); System.out.println("目前创建了" + (++counter) + "个Car类的子类了"); } } static class Car { public void run() { System.out.println("Run..."); } } static class SafeCar extends Car { @Override public void run() { System.out.println("Safe Run..."); super.run(); } } }
接着JVM参数修改为如下,因为我们想看一下GC日志和导出内存快照。
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:MetaspaceSize=10m -XX:MaxMetaspaceSize=10m -XX:+PrintGCDetails -Xloggc:gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./
注意,上面那个HeapDumpPath参数调整为当前项目下,这样方便查看。
(3)分析GC日志
接下来用上述JVM参数运行这段程序,会发现项目下多了两个文件:一个是gc.log,一个是java_pid910.hprof。当然不同的机器运行这个程序,导出的hprof文件的名字是不太一样的,因为hprof文件会用PID进程id作为文件名字。
步骤一:首先分析gc.log
分析它是如何不断往Metaspace区放入大量生成的类,然后触发FGC的。接着回收Metaspace区,回收后还是无法放下更多类,才抛出OOM。
步骤二:然后用MAT分析OOM时的内存快照
也就是使用MAT工具找到Metaspace内存溢出问题的原因,GC日志如下:
CommandLine flags: -XX:CompressedClassSpaceSize=2097152 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./ -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=4294967296 -XX:MaxMetaspaceSize=10485760 -XX:MaxNewSize=348966912 -XX:MaxTenuringThreshold=6 -XX:MetaspaceSize=10485760 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 0.716: [GC (Allocation Failure) 0.717: [ParNew: 139776K->2677K(157248K), 0.0038770 secs] 139776K->2677K(506816K), 0.0041376 secs] [Times: user=0.03 sys=0.01, real=0.00 secs] 0.771: [Full GC (Metadata GC Threshold) 0.771: [CMS: 0K->2161K(349568K), 0.0721349 secs] 20290K->2161K(506816K), [Metaspace: 9201K->9201K(1058816K)], 0.0722612 secs] [Times: user=0.12 sys=0.03, real=0.08 secs] 0.843: [Full GC (Last ditch collection) 0.843: [CMS: 2161K->1217K(349568K), 0.0164047 secs] 2161K->1217K(506944K), [Metaspace: 9201K->9201K(1058816K)], 0.0165055 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 0.860: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1217K(349568K)] 1217K(506944K), 0.0002251 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.860: [CMS-concurrent-mark-start] 0.878: [CMS-concurrent-mark: 0.003/0.018 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 0.878: [CMS-concurrent-preclean-start] Heap par new generation total 157376K, used 6183K [0x00000005ffe00000, 0x000000060a8c0000, 0x0000000643790000) eden space 139904K, 4% used [0x00000005ffe00000, 0x0000000600409d48, 0x00000006086a0000) from space 17472K, 0% used [0x00000006086a0000, 0x00000006086a0000, 0x00000006097b0000) to space 17472K, 0% used [0x00000006097b0000, 0x00000006097b0000, 0x000000060a8c0000) concurrent mark-sweep generation total 349568K, used 1217K [0x0000000643790000, 0x0000000658cf0000, 0x00000007ffe00000) Metaspace used 9229K, capacity 10146K, committed 10240K, reserved 1058816K class space used 794K, capacity 841K, committed 896K, reserved 1048576K
一.第一行GC日志如下
0.716: [GC (Allocation Failure) 0.717: [ParNew: 139776K->2677K(157248K), 0.0038770 secs] 139776K->2677K(506816K), 0.0041376 secs] [Times: user=0.03 sys=0.01, real=0.00 secs]
这行日志,这是第一次GC,它本身是一个Allocation Failure的问题。也就是说,在Eden区中分配对象时,已经发现Eden区内存不足了,于是就触发了一次YGC。
二.那么这个对象到底是什么对象
回到代码中,可知Enhancer是一个对象,它是用来生成类的,如下所示:
Enhancer enhancer = new Enhancer();
接着会基于new Enhancer生成类对象来生成那个子类的对象,如下所示:
Car car = (Car) enhancer.create();
上述代码会在while(true)里不停创建Enhancer对象和Car的子类对象,因此Eden区慢慢就会被占满了,于是会看到上述日志:
[ParNew: 139776K->2677K(157248K), 0.0038770 secs]
这行日志就是说:在默认的内存分配策略下,新生代一共可用空间是150M左右。然后大概用到140M,Eden区都占满了,就会触发Allocation Failure。即没有Eden区的空间去分配对象了,此时就只能触发YGC。
三.接着来看如下GC日志
0.771: [Full GC (Metadata GC Threshold) 0.771: [CMS: 0K->2161K(349568K), 0.0721349 secs] 20290K->2161K(506816K), [Metaspace: 9201K->9201K(1058816K)], 0.0722612 secs] [Times: user=0.12 sys=0.03, real=0.08 secs]
这行日志说明就是发生FGC了,而且通过Metadata GC Threshold清晰看到,是Metaspace区域满了,这时看后面的日志:
20290K->2161K(506816K);
这就是说堆内存(新生代+老年代)一共是500M,有20M被使用了,这20M的内存是被新生代使用的。
然后FGC必然会带着一次YGC,因此这次FGC执行了YGC,所以回收了很多对象,剩下2161K的对象,这2161K的对象大概就是JVM的一些内置对象。
然后直接就把这些对象都放入老年代,为什么呢?因为后面的日志:
[CMS: 0K->2161K(349568K), 0.0721349 secs]
明显表明,FGC带着CMS进行了老年代的Old GC,结果人家本来是0K。然后从新生代转移来了2161K的对象,所以老年代变成2161K了。
接着看日志:
[Metaspace: 9201K->9201K(1058816K)]
这说明此时Metaspace区域已经使用了差不多9M左右的内存了。JVM发现离限制的10M内存很接近了,于是触发了FGC。但是对Metaspace进行GC后发现类的对象全部都还存活,因此还是剩余9M左右的类在Metaspace里。
四.接着来看下一行GC日志
0.843: [Full GC (Last ditch collection) 0.843: [CMS: 2161K->1217K(349568K), 0.0164047 secs] 2161K->1217K(506944K), [Metaspace: 9201K->9201K(1058816K)], 0.0165055 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
接着又是一次FGC。其中的Last ditch collection,说明这是最后一次拯救的机会了。因为之前Metaspace回收了一次但发现没有类可以回收,所以新的类无法放入Metaspace了。因此才再最后试一试FGC,看看能不能回收掉一些。
结果发现还是:
[Metaspace: 9201K->9201K(1058816K)], 0.0165055 secs]
这说明Metaspace区域还是无法回收掉任何类,Metaspace区几乎还是占满了设置的10M内存。
五.继续看如下GC日志
0.860: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1217K(349568K)] 1217K(506944K), 0.0002251 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.860: [CMS-concurrent-mark-start] 0.878: [CMS-concurrent-mark: 0.003/0.018 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 0.878: [CMS-concurrent-preclean-start] Heap par new generation total 157376K, used 6183K [0x00000005ffe00000, 0x000000060a8c0000, 0x0000000643790000) eden space 139904K, 4% used [0x00000005ffe00000, 0x0000000600409d48, 0x00000006086a0000) from space 17472K, 0% used [0x00000006086a0000, 0x00000006086a0000, 0x00000006097b0000) to space 17472K, 0% used [0x00000006097b0000, 0x00000006097b0000, 0x000000060a8c0000) concurrent mark-sweep generation total 349568K, used 1217K [0x0000000643790000, 0x0000000658cf0000, 0x00000007ffe00000) Metaspace used 9229K, capacity 10146K, committed 10240K, reserved 1058816K class space used 794K, capacity 841K, committed 896K, reserved 1048576K
接着JVM就直接退出了,退出的时候打印了当前内存的一个情况:年轻代和老年代几乎没占用。但是Metaspace的capacity是10M,使用了9M左右。无法再继续使用了,所以触发了内存溢出。
此时在控制台会打印出如下的信息:
Caused by: java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:763) ... 11 more
明确抛出异常表明OutOfMemoryError,原因就是Metaspace区域满了。
因此可以假设是Metaspace内存溢出了,然后我们自己监控到了异常。此时直接去线上机器看一下GC日志和异常信息。通过上述分析就能知道系统是如何运行、触发几次GC后引发内存溢出。
(4)分析内存快照
当我们知道是Metaspace引发的内存溢出后:就把内存快照文件从线上机器拷回本地电脑,打开MAT工具进行分析。如下图示: