文章目录
一、问题背景
在周六16:11、16:14分别收到告警邮件,JVM major垃圾回收器频繁警告,60s 秒内发生了 8 次、7 次 major GC;在 16:07 到 17:00 之间,收到 CPU 告警:5台机器 CPU 使用率连续 3 分钟超过阈值 90%,域名的返回码告警:502,每秒300-500次。
17:17开始,域名的返回码告警:504,每秒约200次。
同事将机器重启,其中有一台机器重启后CPU仍飙高,日志显示 Out of memory(同时间段日志里还有很多消息队列异常、rpc异常,异常信息为调用超时)。
二、发现问题
使用 jmap 生成堆转储快照(dump 是以 txt 为后缀的,应该是用 -XX:+HeapDumpOnOutOfMemoryError
参数,在产生OOM 异常之后自动生成的,我起初企图用记事本打开,结果太大了,打不开,2G左右;用 LogViewer 打开,选择 utf-8 编码,有乱码;然后翻了下《深入理解 Java虚拟机》,原来是该用 Java VisualVM 打开),如下:
能看到这些对象占据了大量的空间:
这是使用阿帕奇的 poi 框架,实现导入和导出 excel 功能,创建的对象。
三、关于 poi
poi 导致 OOM 以及解决方案,见后续博客。
四、关于 OOM
现在有几个关于OOM的问题:
OOM 就是内存溢出吗?
简单来说,内存溢出是指程序申请内存大于系统能够提供的内存 ,OOM 是 内存不够用。
可以看看 Oracle 官方的 这篇 Understand the OutOfMemoryError Exception:
https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/memleaks002.html
不过像这次,是因为频繁创建大量对象但是无法回收,先引发 Full GC,而后出现 OOM,应该属于内存泄漏(?个人理解,不一定准确。创建的对象太多了,关键是不能及时被回收,进而导致老年代对象增多,频繁触发 Full GC。如果能及时回收,也就是 Minor GC频繁吧,应该是正常的。但是这份 dump,已经是 发生OOM 时刻的了,可以看到的是大量对象不满足被回收的条件,还在堆中存活),进而导致的内存溢出。
是 OOM 导致CPU飙到近100%的吗?
应该说是OOM 导致不断地 GC,不停消耗 CPU。
为什么消息队列和微服务请求会超时,抛异常?
复习一下虚拟机的知识,判断对象是否存活,用的是可达性分析算法,当对象到 GC Roots 不可达时,说明对象不可用,应予以回收。而可达性分析 对执行时间是很敏感的,体现在 GC 停顿上,因为可达性分析必须在一个能确保一致性的快照中进行——这里的 “一致性” 是指 在整个分析期间,整个执行系统看起来就像被冻结在某个时间点上,不可以出现分析过程中对象引用关系还在不断变化的情况,该点不满足的话,分析结果的准确性就无法得到保障。该点是导致 GC 进行时必须停顿所有 Java 执行线程(Sun 将这件事情称为 Stop the world)的其中一个重要性原因,即使在号称(几乎)不会发生停顿的 CMS 收集器里,枚举根节点时,也是必须要停顿的。
再复习一下内存分配的知识,对象主要分配在新生代 Eden 区,而当 Eden 区没有足够空间进行分配时,虚拟机将发起一次 Minor GC,所谓 Minor GC,就是对新生代进行回收,新生代分为 Eden 和 Survivor区,需要把存活的对象转移进 Survivor 区,不过 Java 对象大多都具备朝生夕灭的特性,所以 Minor GC 非常频繁,一般回收速度也比较快;而所谓 Major GC,也叫 Full GC,是发生在老年代的 GC,出现了 Major GC,经常会伴随至少一次的 Minor GC,Major GC 的速度一般回避 Minor GC 慢 10 倍以上。
我们的程序使用 poi 操作 excel,创建的都是百万级别的对象,那么 Minor GC 后对象突增,会触发 Full GC,也就导致了 Stop the world,因此,此时当前 JVM 的其他服务就会出现大量超时。
OOM 会导致虚拟机退出吗?
由上个问题,服务只是超时了,并不是立刻就挂掉了,可以看出,结论是不会。
查阅资料知,在 Java 虚拟机的运行时数据区域中,除了 程序计数器,其他区域都有可能出现 OutOfMemoryError,而其他区域,也是分情况的,比如直接内存 Direct Memory, 申请 DirectByteBuffer 的时候,如果此时系统的直接存储已经超过了 -XX:MaxDirectMemorySize 设置的上限,那么只是简单的抛出 OutOfMemoryError 异常,这属于逻辑上的 OutOfMemory,具体处理就看程序自身了,如果程序能容忍 OutOfMemory ,就简单抛出一个异常;如果不能容忍,就打印一个日志然后退出。jvm 运行时使用的数据区,申请内存失败时,基本上都是抛出 OutOfMemoryError,Java进程并不会挂掉。
说到底,OutOfMemoryError 也只是一个异常而已,属于 Error 一系非检查异常,复习一下异常的知识,以及 异常 与 线程的关系:
如果线程发生的是 OOM Java heap space,说明是堆空间不够了,然后会由 JVM 在申请分配空间的方法调用上抛出 OOM 异常,线程是独立的,在异常方面,也保持了线程异常的独立性:线程执行中发生的异常,会由线程自身解决,不会抛出到执行它的线程。
( 由 Java 语法保证了实现 Runnable 接口或者继承 Thread 类的子类,其 run 方法也不能声明、抛出任何受查异常 Checked Exception。换言之,在线程方法执行中,发生的任何受查异常,必须在线程中处理。
非受查异常是可以抛出的,线程对于非受查异常,提供了默认的异常处理器:
/**
* Dispatch an uncaught exception to the handler. This method is
* intended to be called only by the JVM. (将未被捕获的异常分发给处理器。这个方法只被JVM调用)
*/
private void dispatchUncaughtException(Throwable e) {
getUncaughtExceptionHandler().uncaughtException(this, e);
}
Thread 的 init() 方法中,线程至少有一个默认异常处理器,兜底的异常处理器 是当前线程父线程的线程组 ThreadGroup,可以看到线程组是有能力处理异常的:
public class ThreadGroup implements Thread.UncaughtExceptionHandler {}
线程通过这两种机制,即 不能声明和抛出受查异常,非受查异常有默认处理器处理,保证内部发生的异常,在线程内解决,而不会抛出给启动线程的外部线程。
)
JVM 退出的条件是虚拟机内不存在非守护线程。 线程发生 OOM 异常,会导致线程结束,而与JVM的退出毫无关系。
写个代码看看效果:
public class Today{
public static void main(String[] args) throws InterruptedException {
new Thread(() -> {
List<Today> list = new ArrayList<>();
while (true) {
list.add(new Today());
}
}).start();
while (true) {
System.out.println(Thread.currentThread().getName() + " continuing...");
Thread.sleep(10L);
}
}
}
可以看到,抛出 OOM 异常,而主线程仍在继续。
五、总结
(猜测之前线上出现OOM异常,导致一台机器挂掉,而其他机器无影响,可能是有个数据量较大的下载请求打到机器上,刚好这时JVM内存达到容量上限了。)
在实例日志中发现 OOM 异常,下一步应该是分析 dump,或许还应该看看 GC 日志(有现成的平台?还是找运维?)。
六、关于同事的答疑
向同事请教,每次oom 导致 CPU 飙高,时伴随着频繁的RPC、消息队列超时,是不是因为 GC 的 stop the world,同事跟我讲了三个知识点:
(1)CPU飙高 是因为同一时间需要处理的东西很多,也就是我们常说的,有资源一直没释放,被堵住了,简单来说,4核CPU理论上 只能同一时间处理4个线程,这还包括系统需要使用 ,那么如果有一个线程一直占用,就会导致资源得不到释放 (所以这几次飙高到底是在处理啥?到底是不是因为 GC 在占用 CPU 资源?)
(2)stop the world,是大家都不干活了,就剩下 GC 的那个线程在清理,清理完,大家一起干活,但是 stop the world 并不是时间就不走了
(3)超时,也有很多种情况,网络层面 ping不通的、(@TCP三次握手,rpc 不是一上来就直接传输数据,传输之前可能需要确认你在不在,维持心跳,握手的阶段或许也是算时间的)人家传输了数据我们却没有及时响应的,都是超时
超时的话,应该从宏观点的角度去看,可能是还没握上手,也可能是对方传输了,但是我们 CPU 告急,而没有来得及处理,似乎不该纠结于 G 不 GC的,GC 还分 young GC、full GC呢,难道你还要区分具体进行了几次 young GC、几次 full GC 吗?
我的理解:JVM 运行起来只是操作系统上一个普通的进程,就算 stop the world 停顿了所有的 java 线程,CPU 还是应该正常执行的,rpc 应该不受影响的(rpc到底受不受java线程停顿的影响啊???存疑),超时只是因为 CPU 资源不够,而不要纠结于 stop the world 的问题。(看了个机器日志,rpc 大量超时,但与此同时并没有 full gc,young gc 也不算频繁,当时也不排除上游的问题 ),疑问似乎没有被直面回应,可能每个人看事情的角度不同吧。