问题
dubbo内部定制的版本中,在处理大于10K的包的时候,会出现内存溢出的现象
原因是我们在定制dubbo http协议的时候,使用了jboss包里面的HttpRequestDecoder的http decoder方法来解析http协议内容
该方法在解析非http协议的大内容时,会出现内存溢出的情况
某个服务因为这个问题,出现了full gc 的情况
复现问题
根据描述复现该问题
- 指定dubbo版本
- dubbo请求,非http请求
- 消息体大于10K
jvm堆配置,jmap -heap pid
Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
MaxHeapSize = 2147483648 (2048.0MB)
NewSize = 44564480 (42.5MB)
MaxNewSize = 715653120 (682.5MB)
OldSize = 89653248 (85.5MB)
NewRatio = 2
SurvivorRatio = 8
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)
构造provider和consumer,然后在consumer的入参约100K,启动tomcat(JVM)的时候添加打印gc详细信息的参数,发起调用的时候观察gc情况
-XX:+PrintGCDetails -XX:+PrintGCDateStamps
第一次调用的时候并没有出现Full GC的情况,想着是不是并发有点小,毕竟线上还是有一定并发量的,所以consumer端启动线程来调用,启动线程个数1、10、100、1000,线程数是1000的时候provider侧出现了FullGC的情况
2018-01-19T21:01:23.758-0800: [GC (Allocation Failure) [PSYoungGen: 454144K->696K(468992K)] 1394833K->1383056K(1867264K), 0.1343399 secs] [Times: user=0.26 sys=0.01, real=0.14 secs]
2018-01-19T21:01:23.892-0800: [Full GC (Ergonomics) [PSYoungGen: 696K->0K(468992K)] [ParOldGen: 1382359K->940805K(1398272K)] 1383056K->940805K(1867264K), [Metaspace: 52098K->52098K(1097728K)], 0.2305879 secs] [Times: user=0.54 sys=0.01, real=0.23 secs]
2018-01-19T21:01:24.629-0800: [Full GC (Ergonomics) [PSYoungGen: 464621K->0K(468992K)] [ParOldGen: 1382601K->941472K(1398272K)] 1847223K->941472K(1867264K), [Metaspace: 52098K->52098K(1097728K)], 0.2063340 secs] [Times: user=0.59 sys=0.00, real=0.21 secs]
2018-01-19T21:01:25.305-0800: [Full GC (Ergonomics) [PSYoungGen: 454693K->0K(468992K)] [ParOldGen: 1383395K->499265K(1398272K)] 1838088K->499265K(1867264K), [Metaspace: 52098K->52098K(1097728K)], 0.1478104 secs] [Times: user=0.34 sys=0.01, real=0.15 secs]
2018-01-19T21:01:25.945-0800: [Full GC (Ergonomics) [PSYoungGen: 457504K->0K(468992K)] [ParOldGen: 1383424K->499950K(1398272K)] 1840928K->499950K(1867264K), [Metaspace: 52098K->52098K(1097728K)], 0.1390671 secs] [Times: user=0.36 sys=0.00, real=0.14 secs]
2018-01-19T21:01:26.585-0800: [Full GC (Ergonomics) [PSYoungGen: 456673K->0K(468992K)] [ParOldGen: 1384488K->499639K(1398272K)] 1841162K->499639K(1867264K), [Metaspace: 52098K->52098K(1097728K)], 0.1344279 secs] [Times: user=0.32 sys=0.01, real=0.14 secs]
jstat -gc pid -t 1s
Timestamp S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
1438.8 1024.0 5120.0 0.0 0.0 443392.0 430848.7 1398272.0 478878.3 53464.0 52117.3 6144.0 5945.4 1733 97.928 949 166.820 264.748
1440.0 1024.0 5120.0 0.0 0.0 443392.0 435843.6 1398272.0 1321492.8 53464.0 52117.3 6144.0 5945.4 1733 97.928 950 166.962 264.889
1441.0 1024.0 5120.0 0.0 0.0 443392.0 433460.4 1398272.0 900800.9 53464.0 52117.3 6144.0 5945.4 1733 97.928 952 167.226 265.153
1441.9 1024.0 5120.0 0.0 0.0 443392.0 0.0 1398272.0 479419.0 53464.0 52117.3 6144.0 5945.4 1733 97.928 954 167.491 265.419
1443.0 1024.0 5120.0 0.0 0.0 443392.0 438270.0 1398272.0 1324328.4 53464.0 52117.3 6144.0 5945.4 1733 97.928 955 167.632 265.560
1444.0 1024.0 5120.0 0.0 0.0 443392.0 437239.3 1398272.0 902696.2 53464.0 52117.3 6144.0 5945.4 1733 97.928 957 167.902 265.830
1445.0 1024.0 5120.0 0.0 0.0 443392.0 440249.7 1398272.0 1326030.9 53464.0 52117.3 6144.0 5945.4 1733 97.928 959 168.046 265.974
1446.0 1024.0 5120.0 0.0 0.0 443392.0 434997.3 1398272.0 903830.7 53464.0 52117.3 6144.0 5945.4 1733 97.928 960 168.341 266.269
1447.0 1024.0 5120.0 0.0 0.0 443392.0 423591.6 1398272.0 480931.8 53464.0 52117.3 6144.0 5945.4 1733 97.928 962 168.610 266.537
问题原因
发生了FullGC,先拿出现在的Heap Dump看看当前JVM的堆内存使用情况
jmap -dump:format=b,file=dump.bin pid
拿到dump文件,拿到MAT中分析下,在dominator_tree视图中找到占用内存较多的对象,这里是byte数组,接下来找到byte数组属于哪一个类,在byte数据上右键"Path To GC Roots" -> "with all reference"就是下图
看到org.jboss.netty.handler.codec.frame.FrameDecoder#cumulation这个对象很大,这个类是HttpRequestDecoder的超类,接下来就是调试源码,查看为什么这个字段会这么大
找到这个字段的所有引用的地方,查看哪里往byte数组(cumulation这个字段包含一个byte数组)中写,主要是下面两个方法
// 这个方法只是把原来的cumulation和新增的input复合到一个对象中,CompositeChannelBuffer
org.jboss.netty.handler.codec.frame.FrameDecoder#appendToCumulation
// 这个方法会对cumulation重新赋值,并把input写入cumulation中,也就是这个时候byte数组会增大
org.jboss.netty.handler.codec.frame.FrameDecoder#updateCumulation
org.jboss.netty.handler.codec.replay.ReplayingDecoder#messageReceived方法中调用上面这两个方法,ReplayingDecoder是HttpRequestDecoder的超类,在接收到请求的时候会调用messageReceived方法,所以在接收到请求的时候就会向cumulation中写数据。
那么现在问题基本清晰了,不断往byte数组中写数据导致byte数组不断增大,问题应该出在byte数组没有被清空上,所以现在的问题是
为什么cumulation没有被清空?
查找所有cumulation被清空的方法
org.jboss.netty.handler.codec.replay.ReplayingDecoder#cleanup
看看谁调用了这个方法
// 连接断开的时候调用这个方法
org.jboss.netty.handler.codec.frame.FrameDecoder#channelDisconnected
// 连接关闭的时候调用这个方法
org.jboss.netty.handler.codec.frame.FrameDecoder#channelClosed
所以只有在连接断开或者关闭的时候才会清空cumulation,结论已经呼之欲出了,回到一开始出现的问题
- dubbo请求,非http请求
- 大量并发请求
在接收到dubbo请求的时候,虽然不是http协议,但是还是会执行HttpRequestDecoder这个handler,也就会往cumulation中写数据,但是dubbo协议使用的是长连接(netty维护的长连接),所以dubbo请求的内容都会被加入到cumulation中,直到连接关闭或者断开才会清空,如果并发量大的话就会导致有多个cumulation大对象,如果对空间不够的时候就会引起FullGC。
而http协议一般都是短连接,或者有超时时间(服务端超时或者客户端超时),这样cumulation就会被及时清空,所以http协议不容易出现这种问题,而dubbo协议更容易出现的原因。
解决问题
既然是非http请求就不需要使用HttpRequestDecoder做进一步处理,所以新建一个类HttpRequestWrapDecoder继承自HttpRequestDecoder,重写messageReceived方法,在该方法里面判断是否是http请求,如果是http请求才会进一步处理,否则直接返回不处理,执行pipeline中下一个handler