問題
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
