遇到Java記憶體溢位(OOM)時，這樣排查

一次Java記憶體溢位排查程序

背景

上周，我們專案中UAT環境突然無法訪問了，查看了日志發現專案在報錯 java.lang.OutOfMemoryError: ......java heap space..... ,雖然是UAT環境，但是所有在未發布之前所出現的問題，我們都應該重視，防止在生產上出現同樣的問題，

修復措施

由于UAT環境，產品需要立馬使用，所以我們需要先保證UAT環境可用，所以我們做了以下操作（本專案是集群搭建）

1. 先查看所有節點是否都是因為記憶體溢位的問題 使用 docker stats發現所有節點的記憶體占用以及cpu占用都已經超負荷了
2. 使用 docker inspect CONTAINER_ID，可以直接看到當前實體運行的是什么專案程式
3. 我們打算先重啟部分當前專案的節點，先保證UAT環境暫時可用
4. 重啟后，再次使用 docker stats 發現重啟后的節點 記憶體還是在 60% 左右浮動，此時訪問當前專案發現是可以訪問了，

因為UAT暫時可用使用了，所以接下來就是我們自己的排查時間了，但是因為重啟后的節點 記憶體還是居高不下，所以我們也需要迅速排查出來問題，否則已經重啟的節點還是隨時可能記憶體溢位

排查原因

哪些節點出現了問題

上述 修復措施 時我們已經找到了 專案中的 CONTAINER_ID，所以我們直接進入 實體內部具體看看是因為什么 導致的記憶體和CPU超負荷的問題，

docker inspect CONTAINER_ID //查看當前docker實體的詳細資訊，可以直接看出當前實體是什么專案
docker exec -it CONTAINER_ID /bin/bash  //進入docker實體
top //查看當前實體內行程情況
top -Hp PID // 找到記憶體和CPU占用率最高的PID 查看當前行程的所有執行緒占用情況
printf "%x\n" Thead_PID // 把執行緒PID 轉換成 16進制 ，因為我們在做堆疊排查時需要使用到 16進制的執行緒PID

到這里我們基本上前期的準備都做好了，接下來我們就應該去排查程式內到底時因為什么執行緒，或者那些物件占用了這么高的記憶體和CPU

小插曲

因為我們需要排查Java程式堆疊資訊，所以我們必須要用到當前Java程式所運行的JDK自帶的排查命令，但是這里很可惜，由于我們專案使用的基礎鏡像是閹割版的 JDK 我在 jdk/bin 下面沒有找到相關命令，由于重新使用完整版基礎鏡像啟動實體，實體本身就會被重啟，如果重啟了那可能還需要等到下一次發生該問題的時候我們才能排查，所以我們做了另一個決定，找一個當前相同版本的JDK 將 當前的 Java環境更改為這個完整版的JDK的環境，但是我們并沒有操作成功，在執行相關排查命令的時候一直提示我 當前環境和本身Java程式環境不匹配，可能是因為中間出現了什么問題，這個就沒有去深究下去了，所以我們還是選擇了，更換鏡像后重啟當前實體節點，

使用JDK命令查看Java程式當前的執行緒狀態

一天后,我們發現UAT再次無法訪問，我們通過上述的操作定位到有問題的docker實體,排查程序如下

jstack -l PID > jastck_PID.log // 使用jstack可以看到當前程式中所有執行緒資訊

我們使用上述中 將執行緒ID轉換成16進制后的 標識，作為搜索條件

grep 16進制的執行緒ID -A20 -B20 jastck_PID.log 

這樣我們就能看到到底是哪個執行緒出現了 占用CPU或者記憶體超載的問題，從而找到對應的業務代碼，但是很可惜，我們發現我們這個執行緒是程式在執行GC操作時所產生的執行緒，所以很明顯這是一個由于記憶體溢位，而導致Java程式一直執行GC操作，引發的CPU超負荷的問題，于是我們繼續排查當前專案所占用的記憶體情況

使用JDK命令查看當前Java專案GC執行次數

由于我們在上述排查時發現CPU超負荷的問題是在于GC執行緒，我們首先先使用查看當前專案GC執行次數的命令，確定當前GC執行情況

jstat -gcutil PID 2000 10 //每兩秒取樣一次當前行程的記憶體情況

我們執行當前命令會看到當前行程中的記憶體占用情況，下面是每一列的官方解釋:

S0:	Survivor space 0 utilization as a percentage of the space's current capacity.
S1:	Survivor space 1 utilization as a percentage of the space's current capacity.
E:	Eden space utilization as a percentage of the space's current capacity.
O:	Old space utilization as a percentage of the space's current capacity.
P:	Permanent space utilization as a percentage of the space's current capacity.
YGC:	Number of young generation GC events.
YGCT:	Young generation garbage collection time.
FGC:	Number of full GC events.
FGCT:	Full garbage collection time.
GCT:	Total garbage collection time.

我們發現我們的年輕代,老年代,永久代的記憶體占用情況基本上都是百分百了,同時在取樣的程序中發現GC的執行時間一直在增加,但是GC次數沒有增加,說明我們行程在執行GC時,有無法回收的物件,導致行程在一直GC

使用JDK命令查看當前Java專案的記憶體詳情

jmap，為了獲取的資料準確，可能會掛起執行緒，會導致應用暫停

jmap -heap PID //當前命令可以查看行程中記憶體的占用情況,行程的記憶體配置情況

我們要將記憶體的使用詳情輸出到檔案中，并且通過 Memory Analyzer軟體 詳細查看記憶體物件

jmap -dump:format=b,file=heapdump.dump PID //在當前目錄生成一個 heapdump.dump 檔案,檔案中包含專案中的記憶體物件占用情況
//由于我們目前在docker容器內 無法將檔案傳輸到本機中，所以我們需要退出docker容器后,并且將檔案拷貝到主機內
docker cp CONTAINER_ID:/tmp/heapdump.dump /tmp/heapdump.dump  //將容器內的 /tmp/heapdump.dump 檔案拷貝到主機 /tmp/heapdump.dump 上

我們再將檔案傳輸到本機中，使用 Memory Analyzer 軟體進行記憶體物件排查，這里就不在闡述 Memory Analyzer 軟體的使用了

查明真相

通過上述一番操作后,我們發現 每次重啟專案，作業流都會重新部署一次流程定義，而作業流中的流程定義會作為快取直接放在程式記憶體中，由于每次啟動專案作業流定義重新生成，老的作業流定義沒有標記未棄用狀態，所以當快取作業流定義的時候會將所有的作業流定義都快取到記憶體中，所以我們在啟動專案后記憶體就占用到 60% 左右，同時我們還發現，我們在使用redis lettuce連接時，使用了 netty的池化操作，并且沒有釋放當前池化緩沖區，導致redis lettuce 會直接占用剩余部分記憶體，

解決問題

我們既然已經查明真相，接下來我們就應該基于真相，進行相應的措施，保證環境不在發生當前問題

1. 由于我們UAT環境，程式記憶體限制最大只有1G ,我們首先增大UAT的記憶體限制
2. 由于作業流的問題，經過排查發現在撰寫作業流部署時有一個BUG，在比較當前流程定義檔案和上一次流程定義檔案時是否有變更，如果有變更才會重新部署流程定義，比較方法有些問題我們進行了改進
3. 針對于redis lettuce連接的問題，我們覺得既然 lettuce 使用了 netty 的池化操作 那我們就暫時不去變更他的操作，僅僅是減少了 池化記憶體大小的配置