skywalking內(nèi)存泄露排查
背景介紹
最近寫的關(guān)于dubbo內(nèi)存泄露稍微復(fù)雜了一點，很多人表示看不明白，想到之前遇到的比較簡單的內(nèi)存泄露問題，更容易入門，于是拿出來分享一下。
為了做微服務(wù)的熔斷降級限流，引入了sentinel組件，對于sentinel引入到公司內(nèi)部使用只是做了一些簡單的定制化，如持久化配置規(guī)則，監(jiān)控數(shù)據(jù)收集展示，后臺登錄權(quán)限整合等等。
在功能驗證通過的情況下，也做了壓測，性能符合要求，于是就推上了生產(chǎn)做線上灰度。剛開始沒問題，直到有一天線上配置了一條降級規(guī)則，并且觸發(fā)了，監(jiān)控告警就炸了鍋。
開始是服務(wù)出現(xiàn)大量慢請求，后來服務(wù)完全僵死。查看監(jiān)控，慢請求很多，cpu飆升，full GC頻繁，內(nèi)存占滿，日志中也出現(xiàn)了java.lang.OutOfMemoryError，可以斷定是內(nèi)存問題了。
問題排查
由于當(dāng)時對系統(tǒng)的操作只有開啟了降級規(guī)則，于是立馬刪除規(guī)則并重啟，系統(tǒng)恢復(fù)，但并沒有保存一份內(nèi)存的dump文件。想著如果問題能復(fù)現(xiàn)就好查了，在當(dāng)初的預(yù)發(fā)機(jī)器上試了一下，并沒有復(fù)現(xiàn)。思前想去，難道跟機(jī)器有關(guān)？于是線上摘下一臺機(jī)器來，配置規(guī)則，稍微壓測一下，果然出現(xiàn)了問題。
能復(fù)現(xiàn)就好辦，趕緊dump內(nèi)存，很多人不知道怎么dump java的內(nèi)存文件，可以使用jdk自帶的jmap命令來dump，使用jmap dump內(nèi)存時會觸發(fā)一次full GC，所以線上使用要謹(jǐn)慎，full GC保證了dump出來內(nèi)存里的對象都是存活的（無法釋放）。
jmap?-dump:format=b,file=dump.bin?${pid}dump出來后的內(nèi)存如果太大，可以使用tar命令壓縮一下再下載到本地分析。分析工具使用eclipse的插件mat，它的官方地址如下
https://www.eclipse.org/mat/
eclipse mat
從dump文件可以看到dubbo的線程每個都占用了2%的內(nèi)存，該應(yīng)用設(shè)置了200個線程，理論上已經(jīng)把內(nèi)存撐爆了。展開一個線程看看
該dubbo線程中存在一個很大的StringBuilder對象，將其值復(fù)制出來，發(fā)現(xiàn)這個字符串竟然有200MB，其中只有第一行不一樣，后面都是重復(fù)的字符串。
com.alibaba.csp.sentinel.slots.block.SentinelRpcException: com.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowExceptioncom.alibaba.csp.sentinel.slots.block.flow.FlowException...
查看dubbo的源碼也沒有發(fā)現(xiàn)有這個屬性，只知道跟sentinel有關(guān)。
線索難以查出真相，很多時候就是這樣，內(nèi)存泄露問題從內(nèi)存本身只能分析出一點線索，不足以找出真相，除非它是個非常簡單的問題。
以經(jīng)驗來看，內(nèi)存泄露問題都會伴隨著cpu升高，因為內(nèi)存不夠使用觸發(fā)full GC，但full GC又無法釋放內(nèi)存，惡性循環(huán)，所以一開始并沒有去看cpu的問題。抱著試一試的態(tài)度再次復(fù)現(xiàn)了現(xiàn)場，并用jstack命令打印出線程棧，想看看除了GC線程外還有沒有線程占用了cpu
jstack?${pid}?>?jstack.txt果然發(fā)現(xiàn)了問題
:20880-thread-200" #532 daemon prio=5 os_prio=0 tid=0x00007f264c1f8000 nid=0x581a waiting for monitor entry [0x00007f25bae09000]: BLOCKED (on object monitor)at java.util.Arrays.copyOf(Arrays.java:3332)at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124)at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:448)at java.lang.StringBuilder.append(StringBuilder.java:136)at org.apache.skywalking.apm.agent.core.context.util.ThrowableTransformer.printExceptionInfo(ThrowableTransformer.java:57)at org.apache.skywalking.apm.agent.core.context.util.ThrowableTransformer.convert2String(ThrowableTransformer.java:34)at org.apache.skywalking.apm.agent.core.context.trace.AbstractTracingSpan.log(AbstractTracingSpan.java:152)at org.apache.skywalking.apm.agent.core.context.trace.ExitSpan.log(ExitSpan.java:112)at org.apache.skywalking.apm.agent.core.context.trace.ExitSpan.log(ExitSpan.java:38)at org.apache.skywalking.apm.plugin.dubbo.DubboInterceptor.dealException(DubboInterceptor.java:124)at org.apache.skywalking.apm.plugin.dubbo.DubboInterceptor.handleMethodException(DubboInterceptor.java:115)at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:97)at ...
從堆棧發(fā)現(xiàn)是skywalking一直在執(zhí)行Arrays.copy，skywalking簡單來說是一款采集分布式調(diào)用鏈的組件，它的原理是針對java代碼中的“調(diào)用“處進(jìn)行字節(jié)碼增強(qiáng)，達(dá)到對業(yè)務(wù)零侵入獲取調(diào)用信息，github地址如下
https://github.com/apache/skywalking
skywalking
這就解釋了為什么壓測時發(fā)現(xiàn)不了這個問題，因為壓測機(jī)沒有部署skywalking。
找到這個堆棧基本就算問題解決了，接著去看代碼就行。
在skywalking上報exception時會把棧都放到StringBuilder中，但是這里出現(xiàn)了bug，在stackTrace為空的時候，就會出現(xiàn)循環(huán)append，直到內(nèi)存耗盡
同時，也在github上找到了對這個bug的修復(fù)，這里是使用的skywalking版本太老導(dǎo)致
https://github.com/apache/skywalking/pull/2931
skywalking bug修復(fù)
這個bug，對于stackTrace不為空的trace時，只能記錄兩層exception，對于stackTrace為空的trace直接OOM，也就是說sentinel因為限流降級拋出的異常stackTrace為空。這里給出sentinel的BlockException部分代碼，它重寫了fillInStackTrace方法，直接返回this。
public abstract class BlockException extends Exception {public Throwable fillInStackTrace() {return this;}...}
這個方法默認(rèn)實現(xiàn)是借助native方法，這里重寫后直接返回this，則是不記錄棧信息
/*** Fills in the execution stack trace. This method records within this* {@code Throwable} object information about the current state of* the stack frames for the current thread.**If the stack trace of this {@code Throwable} {@linkplain
* Throwable#Throwable(String, Throwable, boolean, boolean) is not* writable}, calling this method has no effect.** @return a reference to this {@code Throwable} instance.* @see java.lang.Throwable#printStackTrace()*/public synchronized Throwable fillInStackTrace() {if (stackTrace != null ||backtrace != null /* Out of protocol state */ ) {fillInStackTrace(0);stackTrace = UNASSIGNED_STACK;}return this;}private?native?Throwable?fillInStackTrace(int?dummy);
我們也知道如果異常棧太深會影響性能，對于sentinel這種需要非常高性能的組件直接去掉異常棧信息不失為一種優(yōu)化性能的“黑科技”。這也給我們一個提醒，壓測系統(tǒng)性能時不光要考慮正常情況，也需要考慮異常情況。如果壓測一個系統(tǒng)能抗住5000qps的正常請求，拋出異常只能承受2000qps，那么正常壓測出的5000在實際生產(chǎn)中可能是達(dá)不到的。
總結(jié)
內(nèi)存泄露問題伴隨著cpu，錯誤率，GC頻繁等問題
內(nèi)存泄露最重要的是拿到現(xiàn)場內(nèi)存dump文件，并用工具結(jié)合源碼分析
如果第二條解決不了問題，則需要尋找新的突破口，比如jstack等
相關(guān)內(nèi)容推薦