原創：扣釘日記（微信公眾號ID：codelogs），歡迎分享，轉載請保留出處。
簡介
上次解決了GC長耗時問題後，系統果然平穩了許多，這是之前的文章《GC耗時高，原因竟是服務流量小？》
然而，過了一段時間，我檢查GC日誌時，又發現了一個GC問題，如下：
從這個圖中可以發現，我們GC有一些尖峰，有時會突然有大量的記憶體分配。
檢視GC日誌，發現有大物件分配的記錄，如下：
$ grep 'concurrent humongous allocation' gc.log | awk 'match($0,/allocation request: (\w+) bytes/,a){print a[1]}' |sort -nr
1941835784
1889656848
可以看到，一次大物件分配，分配大小竟然有1.9G，這誰能抗得住啊！
async-profiler定位大物件分配
上面提到的文章介紹過，使用async-profiler可以很容易的定位大物件分配的呼叫棧，方法如下：
./profiler.sh start --all-user -e G1CollectedHeap::humongous_obj_allocate -f ./humongous.jfr jps
然後使用jmc開啟humongous.jfr檔案，呼叫棧如下：
這是在做thrift反序列化操作，呼叫了TCompactProtocol.readDouble方法，方法程式碼如下：
可是，這裡只建立了8位元組的陣列，怎麼也不可能需要分配1.9G記憶體吧，真是奇了怪了！
經過一番瞭解，這是因為async-profiler是透過AsyncGetCallTrace來獲取呼叫棧的，而AsyncGetCallTrace獲取的棧有時是不準的，Java社群有反饋過這個問題，至今未解決。
問題連結：https://bugs.openjdk.org/browse/JDK-8178287
尋找其它tracer
linux上有很多核心態的tracer，如perf、bcc、systemtap，但它們都需要root許可權，而我是不可能申請到這個許可權的?
在使用者態上，基於ptrace系統呼叫實現的有strace、ltrace，我試了一下它們，並無法直接跟蹤G1中的大物件分配函式G1CollectedHeap::humongous_obj_allocate。
我也在網上搜尋了好幾天，希望找到一個有用的純使用者態tracer，但可惜幾天都沒找到，最後，我只能將目標放在c/c++的除錯工具gdb上，我想gdb既然是一個除錯工具，那它必然能夠檢視指定函式的呼叫引數與呼叫棧，只要找到相應用法即可！
編寫gdb指令碼
經過一番學習與探索(PS：其實花了我快2周?)，我終於編寫出了實際可用的gdb指令碼，如下：
handle all nostop noprint pass
handle SIGINT stop print nopass
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060)
while 1
continue
# 如果是Ctrl+c，則退出
if $_siginfo
if $_siginfo.si_signo == 2
detach
quit
end
end
printf "word_size is %d\n",$rsi
if $rsi > 100*1024*1024/8
# 列印當前時間
shell date +%FT%T
# 列印當前執行緒
thread
# 列印當前呼叫棧
bt
python import subprocess
# 向jvm傳送kill -3訊號，即SIGQUIT訊號
python proc = subprocess.Popen(['kill','-3',str(gdb.selected_inferior().pid)], stdout=subprocess.PIPE, stderr=subprocess.PIPE, bufsize=1, universal_newlines=True)
python stdout, stderr = proc.communicate()
python print(stdout)
python print(stderr)
detach
quit
end
end
沒學過gdb的同學可能看不明白，沒關係，我們慢慢來。
handle all nostop noprint pass
handle SIGINT stop print nopass
這2句handle是處理Linux訊號用的，由於我們並不需要除錯訊號問題，所以讓gdb都不處理訊號，保留SIGINT是為了按Ctrl+c時能退出gdb指令碼。
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060)
這個break是給G1中的大物件分配函式G1CollectedHeap::humongous_obj_allocate設定斷點，方法原始碼如下：
word_size參數列示分配多少字的記憶體，而在64位機器上，1字等於8位元組，所以如果能追蹤到這個引數值，就能知道每次分配大物件的大小了。
由於JVM是使用C++寫的，而C++編譯會做函式名改寫(mangle)以相容C的ABI，所以編譯後的函式名就變成了奇奇怪怪的_ZN15G1CollectedHeap22humongous_obj_allocateEmh，透過nm查詢二進位制檔案的符號表，可以獲取這個名稱。
$ which java
/usr/local/jdk/jdk1.8.0_202/bin/java
# jvm相關實現，都在libjvm.so動態庫中
$ find /usr/local/jdk/jdk1.8.0_202 | grep libjvm.so
/usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so
$ nm /usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so |grep humongous_obj_allocate
000000000058c060 t _ZN15G1CollectedHeap22humongous_obj_allocateEmh
000000000058b1a0 t _ZN15G1CollectedHeap41humongous_obj_allocate_initialize_regionsEjjmh
再看回之前設定斷點的指令碼程式碼：
break *(_ZN15G1CollectedHeap22humongous_obj_allocateEmh + 0x58c06f - 0x58c060)
+ 0x58c06f - 0x58c060這個是在做地址偏移操作，瞭解過彙編的同學應該清楚，呼叫函式後，函式開頭的一些彙編指令，一般是引數暫存器的相關操作，x86引數暫存器如下：
rdi 表示第一個引數
rsi 表示第二個引數
rdx 表示第三個引數
rcx 表示第四個引數
r8 表示第五個引數
r9 表示第六個引數
可以使用objdump反彙編libjvm.so，看看彙編程式碼，以確定斷點該偏移到哪一行指令上，看官們堅持住，彙編相關內容就下面一點?
$ objdump -d /usr/local/jdk/jdk1.8.0_202/jre/lib/amd64/server/libjvm.so |less -S
然後在less裡面搜尋_ZN15G1CollectedHeap22humongous_obj_allocateEmh函式，如下：
之所以要加偏移量，是因為在 + 0x58c06f - 0x58c060這個位置後，rsi暫存器(第二個引數)才會有值，之所以獲取每二個引數的值，是因為C++物件程式設計中，第一個引數是this。
然後後面的邏輯就好理解了，如下：
首先是迴圈，然後continue表示讓程式執行起來，當程式命中斷點後，continue才會執行完。
中間是訊號處理，主要是為了能Ctrl+c退出迴圈。
最後透過print將rsi的值列印出來，這樣就追蹤到了word_size引數的值。
再然後是列印執行緒與呼叫棧資訊，如下：
當分配記憶體大於100M時，列印當前時間、當前執行緒與當前呼叫棧。
但gdb的bt命令列印的呼叫棧是這樣子的，如下：
因為Java是解釋執行的，java部分的呼叫棧bt是獲取不到的。
沒有java呼叫棧，這個追蹤指令碼就瘸了呀，我在這裡卡了好久，也嘗試了許多種方法?
對java比較熟悉的同學應該知道，jvm有一個隱藏的診斷功能，如果給jvm程式發SIGQUIT訊號，jvm會在標準輸出中列印執行緒棧資訊，而SIGQUIT訊號可以透過kill -3傳送，因此就有了下面的程式碼：
gdb真是強大，內嵌了python擴充套件，而透過python的subprocess包，就可以執行kill -3命令了。
後面的detach與quit，用於退出gdb的，不用深究。
執行gdb指令碼追蹤大物件
把上面的gdb指令碼命名為trace.gdb，然後就可以使用gdb命令執行它了，如下：
$ gdb -q --batch -x trace.gdb -p `pgrep java`
其中pgrep java用於獲取java程式的程式號。
注：gdb本質上是基於ptrace系統呼叫的偵錯程式，斷點命中時對程式有不小切換開銷，所以這種方式只能追蹤呼叫頻次不高的函式。
執行後，追蹤到的引數與執行緒資訊如下：
其中LWP後面的166就是執行緒號，轉成十六進位制就是0xa6。
然後到java程式的標準輸出日誌中，去找這個執行緒的Java呼叫棧，如下：
大物件分配由readBinary函式發起，除錯下這個函式，如下：
媽呀，它建立了一個超大的byte陣列，難怪會出現1.9G的大物件分配呢！
而readBinary的呼叫，由這個程式碼觸發：
TProtocolFactory factory = new TCompactProtocol.Factory();
TDeserializer deserializer = new TDeserializer(factory);
deserializer.deserialize(deserializeObj, sourceBytes);
這是在做thrift反序列化，將sourceBytes位元組陣列反序列化到deserializeObj物件中。
當sourceBytes是由deserializeObj物件序列化出來時，反序列化就沒有任何問題。
而當sourceBytes不是由deserializeObj物件序列化出來時，反序列化程式碼從sourceBytes中解析出欄位長度時(length)，可能是任意值，進而導致可能建立超大的位元組陣列。
但我們寫這個程式碼，就是為了檢測sourceBytes是否由deserializeObj序列化而來，所以sourceBytes確實有可能不是由deserializeObj序列化而來！
簡單檢視了一會thrift程式碼，發現可以限制欄位的最大長度，如下：
想一想，反序列的某個欄位的長度，肯定不會有整個反序列化的資料長呀，因此使用sourceBytes.length來限制即可。
TProtocolFactory factory = new TCompactProtocol.Factory(sourceBytes.length, sourceBytes.length);
TDeserializer deserializer = new TDeserializer(factory);
deserializer.deserialize(deserializeObj, sourceBytes);
限制了後，若欄位超長了會拋異常，所以若反序列化異常了，說明當前sourceBytes不是由deserializeObj序列化出來。
總結
編寫這個gdb指令碼，確實花費了我相當多的時間，因為事前我也不知道gdb是否能夠做到這個事情，且我不是C/C++程式設計師，對彙編相關知識並不熟悉，中途有好幾次想放棄?
好在最後成功了，並讓我又Get到了一種新的問題解決路徑，還是非常值得的?