一次容器化springboot程式OOM問題探險
背景
運維人員反饋一個容器化的java程式每跑一段時間就會出現OOM問題,重啟後,間隔大概兩天後復現。
問題調查
一查日誌
由於是容器化部署的程式,登上主機後使用docker logs ContainerId檢視輸出日誌,並沒有發現任何異常輸出。 使用docker stats檢視容器使用的資源情況,分配了2G大小,也沒有發現異常。
二缺失的工具
打算進入容器內部一探究竟,先使用docker ps 找到java程式的ContainerId
,再執行docker exec -it ContainerId /bin/bash進入容器。進入後,本想著使用jmap、jstack 等JVM分析命令來診斷,結果發現命令都不存在,顯示如下:
bash: jstack: command not found
bash: jmap: command not found
bash: jps: command not found
bash: jstat: command not found
突然意識到,可能打映象的時候使用的是精簡版的JDK,並沒有這些jVM分析工具,但是這仍然不能阻止我們分析問題的腳步,此時docker cp命令就派上用場了,它的作用是:在容器和宿主機之間拷貝檔案。這裡使用的思路是:拷貝一個新的jdk到容器內部,目的是為了執行JVM分析命令,參照用法如下:
Usage: docker cp [OPTIONS] CONTAINER:SRC_PATH DEST_PATH|- docker cp [OPTIONS] SRC_PATH|- CONTAINER:DEST_PATH [flags]
有了JVM工具,我們就可以開始分析咯。
三查GC情況
通過jstat檢視gc情況
bin/jstat -gcutil 1 1s
看樣子沒有什麼問題,full gc也少。再看一下物件的佔用情況,由於是容器內部,程序號為1,執行如下命令:
bin/jmap -histo 1 |more
發現ByteBuffer物件佔用最高,這是異常點一。
四查執行緒快照情況
- 通過jstack檢視執行緒快照情況。
bin/jstack -l 1 > thread.txt
下載快照,這裡推薦一個線上的執行緒快照分析網站。
https://gceasy.io
上傳後,發現建立的執行緒近2000個,且大多是TIMED_WAITING狀態。感覺逐漸接近真相了。 點選詳情發現有大量的kafka-producer-network-thread | producer-X 執行緒。如果是低版本則是大量的ProducerSendThread執行緒。(後續驗證得知),可以看出這個是kafka生產者建立的執行緒,如下是生產者傳送模型:
根據生產者的傳送模型,我們知道,這個sender執行緒主要做兩個事,一是獲取kafka叢集的Metadata共享給多個生產者,二是把生產者送到本地訊息佇列中的資料,傳送至遠端叢集。而本地訊息佇列底層的資料結構就是java NIO的ByteBuffer。
這裡發現了異常點二:建立過多kafka生產者。
由於沒有業務程式碼,決定寫一個Demo程式來驗證這個想法,定時2秒建立一個生產者物件,傳送當前時間到kafka中,為了更好的觀察,啟動時指定jmx埠,使用jconsole來觀察執行緒和記憶體情況,程式碼如下:
nohup java -jar -Djava.rmi.server.hostname=ip
-Dcom.sun.management.jmxremote.port=18099
-Dcom.sun.management.jmxremote.rmi.port=18099
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false -jar
com.hyq.kafkaMultipleProducer-1.0.0.jar 2>&1 &
連線jconsole後觀察,發現執行緒數一直增長,使用記憶體也在逐漸增加,具體情況如下圖:
故障原因回顧
分析到這裡,基本確定了,應該是業務程式碼中迴圈建立Producer物件導致的。
在kafka生產者傳送模型中封裝了 Java NIO中的 ByteBuffer 用來儲存訊息資料,ByteBuffer的建立是非常消耗資源的,儘管設計了BufferPool來複用,但也經不住每一條訊息就建立一個buffer物件,這也就是為什麼jmap顯示ByteBuffer佔用記憶體最多的原因。
總結
在日常的故障定位中,多多使用JDK自帶的工具,來幫助我們輔助定位問題。一些其他的知識點:
jmap -histo顯示的物件含義:
[C 代表 char[]
[S 代表 short[]
[I 代表 int[]
[B 代表 byte[]
[[I 代表 int[][]
如果匯出的dump檔案過大,可以將MAT上傳至伺服器,分析完畢後,下載分析報告檢視,命令為:
./mat/ParseHeapDump.sh active.dump org.eclipse.mat.api:suspects
org.eclipse.mat.api:overview org.eclipse.mat.api:top_components
可能儘快觸發Full GC的幾種方式
1) System.gc();或者Runtime.getRuntime().gc();
2 ) jmap -histo:live或者jmap -dump:live。
這個命令執行,JVM會先觸發gc,然後再統計資訊。
3) 老生代記憶體不足的時候