问题背景
项目整体上是微服务架构,微服务之前通过http的restfull请求交互。问题出现在接收其他微服务http响应的时候。单个微服务的启动参数-Xmx512m,即最大内存为512M。
报错信息
首先获取日志信息:
java.lang.OutOfMemoryError: Java heap space
at java.nio.HeapByteBuffer.<init>(HeapByteBuffer.java:57) ~[?:1.8.0_212]
at java.nio.ByteBuffer.allocate(ByteBuffer.java:335) ~[?:1.8.0_212]
at org.eclipse.jetty.util.BufferUtil.allocate(BufferUtil.java:116) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.ByteBufferPool.newByteBuffer(ByteBufferPool.java:61) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.MappedByteBufferPool.acquire(MappedByteBufferPool.java:65) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.GZIPContentDecoder.acquire(GZIPContentDecoder.java:408) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.GZIPContentDecoder.decodedChunk(GZIPContentDecoder.java:108) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.GZIPContentDecoder.decodeChunks(GZIPContentDecoder.java:189) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.GZIPContentDecoder.decode(GZIPContentDecoder.java:71) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.HttpReceiver.responseContent(HttpReceiver.java:347) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.content(HttpReceiverOverHTTP.java:283) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1787) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1517) ~[jetty-http-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:172) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:135) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:73) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:155) ~[jetty-client-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:411) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:305) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:159) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) ~[jetty-io-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
通过错误堆栈可以看到,发生内存溢出时,正在解析http响应的body体。
通常 OutOfMemoryError 堆栈,并不能确定问题的根因。
如果系统存在内存泄漏,并且内存接近上限,此时,当正常业务流程需要申请一部分内存时,如果总量超过了最大内存,会抛出内存溢出异常。通过此时的堆栈,并不能找到问题的根因。
分析 .hprof 文件内容
接下来通过MAT查看hprof文件
450m以上的内存是一个MappedByteBufferPool对象。此处应该就是问题的根因。也正是问题发生时的log调用堆栈中的对象。
先大概查看一下源码。MappedByteBufferPool.java是一个内存缓冲池,提供了申请内存和释放内存的方法。 MappedByteBufferPool内存过高应该就是只申请而没有释放。 从源码上看释放内存应该是调用者的职责。
所以接下来通过调用栈,调用者是GZIPContentDecoder.java。从名字上看应该是在解压gzip的报文。
响应报文过大导致溢出?
通过之前的业务日志和业务代码上推断此处报文大小最多也就是几M的数量级,不会出现400多M的情况。
继续通过MAT查看内存的详细信息
内存缓存池以map形式存在,key是int,并且相邻两个key对应的内容相差2048字节内存。
通过上述分析,推断该问题可能是jetty框架的问题。
因为业务代码应该不会接触到 MappedByteBufferPool对象,并且业务的报文最大值大约是几M,单纯的业务报文不会导致内存溢出。
如果是开源框架问题,有可能已经有了解决方法,于是google一下。
google 关键字 GZIPContentDecoder + OutOfMemoryError 发现第一个在官方jetty项目下有个issue描述与此问题类似。
查看issue内容后发现,正是此问题,并且最新版本已经修复了该问题。
https://github.com/eclipse/jetty.project/issues/3373
https://github.com/eclipse/jetty.project/commit/057575f1cb8fd2c0c35e8eeeb26b726c1d4cea99
总结
org.eclipse.jetty.io.MappedByteBufferPool
org.eclipse.jetty.client.HttpClient
org.eclipse.jetty.http.GZIPContentDecoder
MappedByteBufferPool:提供缓存池,当前版本存在缺陷,缓存大小无上限
HttpClient:创建MappedByteBufferPool和GZIPContentDecoder,用于http通信消息的处理
GZIPContentDecoder: 当消息内容是经过压缩的,使用此类进行解压,解压过程也会使用到HttpClient创建的MappedByteBufferPool
GZIPContentDecoder的缺陷:无法确定解压的后内容的大小,先申请一块缓存,解压后确认大小是否够用,不够的话增加大小重新申请一块缓存,重新解压,这个过程会导致一个压缩报文反复申请缓存,逐渐增加大小,直到申请到合适大小的缓存才能成功,这过程重申请的缓存最终都被放入MappedByteBufferPool缓存池,产生的缓存大小为:2048 + 20482 +20483 + … … +2048*n,一个解压后大小为640k的报文,最终产生100M的缓存。
Jetty最新版本 9.4.17,MappedByteBufferPool进行了优化,增加了最大缓存大小的设置,超出会清理,但是默认构造还是不设置上限,并且HttpClient并没有优化后的构造方法,还是存在内存泄漏可能。
GZIPContentDecoder已修复了缺陷,不会反复重新解压,而是分段解压,最后合并结果。