經過btrace排查線上頻繁Full GC的case

概述

又是一次由於線上報警機制開啓的排查問題之旅。某日，釘釘機器人瘋狂報警：

接着就是申請機器權限去排查問題，既然是頻繁Full GC，那咱們排查問題的思路就應該是找到引發Full GC的緣由。引發頻繁Full GC的常見緣由有這麼幾點：

1. 堆外內存達到閾值，將會調用System.gc()來作一次Full GC。這裏說的堆外內存主要說的是nio下的DirectByteBuffer，它會經過Unsafe接口經過os::malloc來分配內存，而後將內存的起始地址和大小存到DirectByteBuffer對象中，只有當DirectByteBuffer被回收掉以後堆外內存纔可能被回收。具體堆外內存回收的細節你們能夠看下笨神的JVM源碼分析之堆外內存徹底解讀.
2. 項目中顯示或隱式的調用了System.gc()。System.gc的詳情可見連接描述
3. 老年代可用空間不夠了，致使它的緣由有多種，可是常見的排查思路經過mat去分析堆內存dump文件。

定位Full GC的緣由

gc日誌永遠都是咱們排查gc問題最好的工具，因此強烈建議你們在線上配置-XX:+PrintGCDetails -Xloggc:/data/logs/gc.log方便咱們去定位問題。因爲當前項目沒有配置，只好用jstat -gccause去監測，博主監測了五分鐘左右，獲得以下信息:新生代、老年代、元空間內存還不少，FGC漲了9次，而且對應的LGCC都顯示爲System.gc.因爲虛擬機參數並無去配置-XX:MaxDirectMemorySize,因此其堆外內存受限於當前物理機內存，故咱們能夠經過top去查看進程佔了多少內存和經過free -m查看空閒內存（固然visualvm的插件和perftools都是查看堆外內存使用狀況很好的工具，不瞭解自行谷歌）。通過內存分析和業務分析以後，初步判定不是堆外內存致使的，而是由項目中有調用System.gc().

如何查找項目哪裏有調用Full GC呢

首先對項目全局進行搜索System.gc(),若是沒有查到，那麼就極可能是依賴的jar包裏存在調用，如何在jar包中查找呢？在這裏給你們推薦一款插件Btracegithub地址。BTrace是Java的安全可靠的動態跟蹤工具。 他的工做原理是經過 instrument + asm 來對正在運行的java程序中的class類進行動態加強。說他是安全可靠的，是由於它對正在運行的程序是隻讀的。也就是說，他能夠插入跟蹤語句來檢測和分析運行中的程序，不容許對其進行修改。所以他存在一些限制：

---

1. 不能建立對象
2. 不能建立數組
3. 不能拋出和捕獲異常
4. 不能調用任何對象方法和靜態方法
5. 不能給目標程序中的類靜態屬性和對象的屬性進行賦值
6. 不能有外部、內部和嵌套類
7. 不能有同步塊和同步方法
8. 不能有循環(for, while, do..while)
9. 不能繼承任何的類
10. 不能實現接口
11. 不能包含assert斷言語句

---

根據官方聲明，不恰當的使用Btrace會致使jvm崩潰，因此在上生產環境以前，必定要在本地充分驗證腳本的正確性。Btrace的常見使用場景有：

1. 分析哪些方法調用System.gc，獲取其調用棧
2. 接口性能差，分析耗時狀況
3. 當出現異常時，分析方法的運行時參數
4. 線上有一個大對象ArrayList，查看其內容

---

安裝使用Btrace

Btrace依賴於JDK，首先要安裝好JDK並配置JDK的環境變量。

1.下載安裝包

下載地址:https://github.com/btraceio/btrace/releases/tag/v1.3.11

2.解壓縮


修改目錄權限:

3.配置環境變量

而後source更新環境變量
4.編寫btrace腳本

import static com.sun.btrace.BTraceUtils.jstack;
import static com.sun.btrace.BTraceUtils.println;
import static com.sun.btrace.BTraceUtils.str;
import static com.sun.btrace.BTraceUtils.strcat;
import static com.sun.btrace.BTraceUtils.timeMillis;

import com.sun.btrace.annotations.BTrace;
import com.sun.btrace.annotations.Kind;
import com.sun.btrace.annotations.Location;
import com.sun.btrace.annotations.OnMethod;
import com.sun.btrace.annotations.TLS;
@BTrace
public class MyTest {
    @OnMethod(clazz = "java.lang.System", method = "gc" )
    public static void startMethod(){
        println("****************************************");
        jstack();
        println("****************************************");
    }
    @OnMethod(clazz = "java.lang.System", method = "gc", location = @Location(Kind.RETURN))
    public static void endMethod(){
        println("=========================================");
        jstack();
        println("=========================================");
    }
}

5.運行btrace

經過jps -l得到進程的pid，而後經過 btrace <pid> <btrace_script> >> gc.txt & 之後臺任務的方式去開啓btrace腳本監聽對應進程，將對應的棧信息保存到gc.txt中。
6.關閉btrace

---

通過長達一天的監控，終於抓到了對應的調用棧：

緣由是項目中用到了jxl的Workbook來作Excel相關的功能,每次關閉Workbook的時候都會調用System.gc

至此，咱們就已經抓住了致使頻繁Full GC的鬼了，改動方法也特別簡單，在構造WorkBook的時候，將其成員變量WorkbookSettings的成員變量gcDisabled設置爲true便可避免此問題，或者添加vm參數-Djxl.nogc=true（不太推薦）.

總結

每次排查問題的時候遇到了不少困難，在總結的時候卻又不知道該說些什麼~.~。特別感謝提供幫助的笨神、阿飛和零度。