深入理解JVM - 分区是如何溢出的?(下)

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: 深入理解JVM - 分区是如何溢出的?(下)

如何排查分区溢出问题?



Tomcat出现OOM如何排查?


在这个案例中,一个每秒仅仅只有100+请求的系统却频繁的因为OOM而崩溃,下面会一步步排查一个这样的问题是如何牵扯到Tomcat和分区溢出扯上关系的。


还原案发现场:


首先,我们需要还原案发现场,在某一天系统突然收到报警,通知说线上系统出了问题。于是排查异常信息,这时候第一件事情是跑到线上看一下日志的结果,结果非常惊讶的发现报错信息如下:


Exception in thread "http-nio-8080-exec-1089" java.lang.OutOfMemoryError: Java heap space
复制代码


这一段和上面模拟的代码结果非常类似,不同的是这个线程是一个Tomcat的线程,当然这个消息非常不好,因为线上居然发生了OOM!这是一个非常严重的BUG。下面来看下是如何一步步进行排查的。


简单了解Tomcat的底层原理


首先我们来简单了解一下Tomcat这种web服务器的工作原理是什么呢?其实学了JVM之后,对这个概念应该有了更深入的了解,毫无疑问就是底层依然还是一个JVM的进程,通常情况下,我们使用Tomcat都会绑定一个8080的端口启动,Tomcat在最开始的时候请求是通过一个叫做Servlet的东西进行处理的,而这个Servlet在后来经过框架的包装就变成了spring mvc的一个mapping,到后续随着框架的演进,现在通常都会使用框架比如说spring boot内置的Tomcat进行web服务器的管理,我们不再需要单独的Tomcat进行项目部署操作,直接集成式一键启动即可。

那么我们的请求是如何被Tomcat解析的呢?Tomcat通过监听端口并把我们发送过来的网络请求经过解析的和处理,然后再传给MVC的进行包装分发,最后到具体的某一个映射(Mapping),整个业务过程其实就是Tomcat把我们写好的类(controller)通过他的类加载器加载到Tomcat的内部进行执行,执行完成之后再结果返回给请求发送方。

那么tomcat是如何监听端口的呢?其实tomcat本身就是一个工作线程,对于我们的每一个请求,tomcat的工作线程都会从自己管理的线程池中分配一个工作线程来负责进行处理,也就是说多个请求之前是相互独立并且互不干扰的。为了更好的理解,下面画了图来简单解释一下上文描述的工作机制:


网络异常,图片无法展示
|


小贴士:

建议在JVM调优的时候务必加上此参数:-XX:+HeapDumpOnOutOfMemoryError。一旦出现OOM等内存溢出的情况时候,JVM会从内存中备份一份当前的溢出日志,根据日志也可以很快的定位到问题发生的点以及产生了什么问题。


内存快照分析:


言归正传,这里再次回到案例来,这里省略具体的分析步骤,最后通过内存快照的结果发现,导致内存泄露的居然是数组,从日志的分析结果中发现了如下的内容:


byte[10008192] @ 0x7aa800000 GET /order/v2 HTTP/1.0-forward...
byte[10008192] @ 0x7aa800000 GET /order/v2 HTTP/1.0-forward...
byte[10008192] @ 0x7aa800000 GET /order/v2 HTTP/1.0-forward...
byte[10008192] @ 0x7aa800000 GET /order/v2 HTTP/1.0-forward...
复制代码


就是类似这样的byte数组,在每一次调用的时候,都产生了大概10M左右大小的数组,最终由于几百次的调用的同时这些数组对象 并不能回收掉,最终导致了内存的溢出。

这时候你可能会认为有人要来背锅了,然而工程师断定代码泄露不是个人编写的代码导致的。接着我们继续思考,不是开发人员造成的,排查代码确实没有看到明显会导致溢出的点,那么这是怎么回事呢?

进一步排查,发现是有一个对象存在长期的占用那就是:org.apache.tomcat.util.threads.TaskThread,从包名字就可以知道是Tomcat自己的线程,这意味着Tomcat在这个线程当中创建了数组并且没有被回收。

既然数组没有被回收也就意味着工作线程还在执行任务,按理来说工作线程执行任务通常都是很快就会完成的,为什么TaskThread会长期等待呢?这里再通过测试和分析发现每一个工作线程居然停留了4秒以上,我们都知道通常情况下一个请求都是在一秒以内完成的,而这里的线程居然停留了长达4秒,这里是一个问题点,另外这里还发现每一个工作线程就创建了2个10M的数组,导致数组也因为还在使用而无法释放,所以这里2个10M的数组又是怎么来的?这是第二个问题点,

通过配置文件的查找发现了下面的内容:


max-http-header-size: 10000000
复制代码


就是这个东西导致了每次Http请求都会创建20M的数组内容。

这里小结一下上面的内容,其实就是说每一个工作线程都创建一个20M数组,意味着100个工作线程就是2000M的大小,并且2000M还无法回收。按照这个速度累积,一旦请求过多JVM就会立马崩溃。


解决问题:


既然知道了是工作线程的问题,那么接下来就要着手解决为什么线程会停留4秒以上以及这个20M数组的来源,在接下来的排查中还发现日志中还有如下的内容:


Timeout Exception....
复制代码


日志大致内容就是RPC的请求出现了大量的连接超时,而连接超时的时间刚好是4秒!通过询问发现原来工程师设置了RPC的超时时间刚好也是4秒,真相大白了!在每一次的工作线程执行代码的时候,都会执行一次RPC的远程调用,而当RPC服务挂掉的时候,此时由于连接远程服务器迟迟得不到响应导致系统需要等待4秒才会释放线程,在等待的时候工作线程会占用这个请求的资源并且卡死在线程上等待结果,如果在同一时间有很多的请求就会出现百来个工作线程挂在自己的线程卡死并且等待响应的结果,最终由于堆内存占用过多的数组对象,无法再分配新的对象导致OOM!

知道了问题,下一步就是解决问题了,这里解决办法也比较简单,首先我们需要把超时的时间设置为1S,一旦RPC连接时间超过1S就立马释放资源,防止工作线程出现远程调用的长时间等待占用资源的问题,另外就是max-http-header-size这个参数可以适当的调整小一点,这样在每次调用的时候就不需要占用过大的数组导致资源利用紧张的问题了。


RPC通信框架导致的内存溢出:



问题情况:


  1. A服务器进行了升级之后,B的远程服务器宕机了,查看日志发现了OOM的异常
  2. 出现了超过4G的数组分配动作,由于JVM的堆不可能放下这种对象,直接导致了OOM
  3. 发现这个对象是RPC内部使用的通信对象构建出来的数组。


案发现场:


系统上有两个服务,服务A和服务B,服务A和服务B之间使用RPC的通信方式,同时使用的序列化协议是ProtoBuf,在通信协议上统一封装的对象格式这里假设使用的是Request,同时在远程调用的时候序列化和反序列化的封装和解析都是自定义的,接着我们在拓展一下细节:


  1. 首先在请求服务A的时候,需要对传输过来的对象进行序列化,这个序列化就是类似于把你的对象转为一个byte[]数组(字节流)
  2. 服务A接受请求并且通过RPC发送到远程服务器B之后,使用RPC通信规则对内容进行序列化转为byte[],服务B接受之后使用反序列化把byte[]数组进行反序列化,拿到对象的内容进行逻辑处理。
  3. 这两个服务之间遵循了自定义的Request的对象格式进行通信,保证序列化和反序列化之后的对象格式和内容一致。


那么问题是什么呢,问题很奇怪,当服务A进行升级之后,部署上去没有几分钟,**发现服务B挂了!**很奇怪,明明改的是服务A却是服务B挂了,经过日志分析,发现也是Byte[]数组太大导致溢出,这里阅读日志之后发现,居然分配了一个4G的数组......


RPC类的框架规则


这里先不急着说明产生问题的原因,我们先补充一下RPC框架的通信规则理论:

一个RPC 的通信框架大致过程:试想一下为了让服务A的所有请求在远程服务B接受之后都能够处理,服务器两边的RPC框架肯定是要对所有的请求对象做统一规范的,比如RPC使用了ProtoBuf作为序列化的协议标准,同时使用固定的对象格式对于对象数据进行序列化和反序列化操作,这里假设服务A序列化使用Request对象进行定制序列化之后发送到服务B,而服务B自然需要使用对应的Request将服务A传来的序列化对象来反序列化。


这里就有一个问题了,如果服务A改动了Request对象的定制格式,比如通信使用Request A+C被序列化之后发送的到服务B了,服务B按照之前的Request解开之后发现自己解不开对象,于是会创建一个byte[] 数组来存放序列化的数据,让客户端自己去完成反序列化的操作。


排查结果:


排查的结果就是服务A改了Request而m没有通知服务B修改对应的对象,导致反序列化失败并且新建了一个Byte[]数组来存放序列化的数据,而这个数组默认值刚刚好就设置了4G的大小!为什么要设置这么大的数组?开发人员说怕数组过小放不下,所以构建了一个4G的数组,保证无论A服务发送的对象如何大也不会影响到B。


解决问题:


很简单只要把这个反序列化失败之后创建数组的大小改小一点就行了,改成4M的大小基本足够应付大部分的情况。


总结


这一节主要讲述了分区的问题以及实际的案例中分区溢出的问题是如何排查的,可以看到虽然我们都十分清楚分区溢出是什么情况,但是到实际的案例中进行排查却又是五花八门的问题出现,希望通过案例讲解让更多的同学可以了解到JVM是如何进行问题排查,同时这里也可以发现,平时还是需要对于底层基础知识进行多积累,很多时候并不是学到的东西用不上,而是到了用上的时候你没学。所以平时多磨练一下自己的脑袋,遇到问题才不会手足无措。


写在最后:

不知道为什么时候在方法区的溢出实际运行测试的时候个人的笔记本电脑死活不能溢出,即使设置了参数也是方法区不断的溢出,难道是我是AMD的CPU的问题???

相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
相关文章
|
5月前
|
存储 算法 安全
(八)JVM成神路之GC分区篇:G1、ZGC、ShenandoahGC高性能收集器深入剖析
在《GC分代篇》中,我们曾对JVM中的分代GC收集器进行了全面阐述,而在本章中重点则是对JDK后续新版本中研发推出的高性能收集器进行深入剖析。
173 12
|
5月前
|
监控 算法 Java
JVM调优---堆溢出,栈溢出的出现场景以及解决方案
【7月更文挑战第3天】堆溢出(Heap Overflow)和栈溢出(Stack Overflow)是两种常见的内存溢出问题,通常发生在内存管理不当或设计不合理的情况下
65 3
|
7月前
|
消息中间件 Java 应用服务中间件
深入理解JVM - 如何排查分区溢出问题
深入理解JVM - 如何排查分区溢出问题
91 0
|
7月前
|
缓存 前端开发 Java
深入理解JVM - 分区是如何溢出的?
深入理解JVM - 分区是如何溢出的?
85 0
|
算法 Java UED
jvm之垃圾回收分代收集算法、 增量收集算法、分区算法解读
jvm之垃圾回收分代收集算法、 增量收集算法、分区算法解读
|
消息中间件 缓存 Java
深入理解JVM - 如何排查分区溢出问题
这篇文章会接续上一篇关于分区溢出的案例实战内容再次补充几个OOM的案例,本文不再讲述新内容,以案例实战为主,希望这些案例能帮助同学们了解到更多JVM关于OOM溢出的排查套路。
83 0
|
缓存 监控 前端开发
深入理解JVM - 分区是如何溢出的?
JVM运行时分区溢出学习JVM必须掌握的一块内容,同时由于JVM的升级换代,JVM的内部分区也在逐渐的变化,比如方法区的实现由永久代改为了元空间这些内容都是需要掌握的,这一节将会是一篇关于JVM分区溢出的总结,同样根据两个案例来说下如何排查JVM令人头痛的OOM问题。
54 0
|
缓存 IDE Java
深入理解JVM - 分区是如何溢出的?(上)
深入理解JVM - 分区是如何溢出的?(上)
91 0