一次線上JVM GC 長暫停排查，加班搞了好久

2024-03-11 08:51:08

JVM進行GC時，需要對對應(yīng)堆分區(qū)的已用內(nèi)存進行遍歷，假如GC的時候，有堆的一部分內(nèi)容被交換到swap中，遍歷到這部分的時候就須要將其交換回內(nèi)存；更極端情況同一時刻因為內(nèi)存空間不足，就需要把內(nèi)存中堆的另外一部分換到SWAP中去，于是在遍歷堆分區(qū)的過程中，會把整個堆分區(qū)輪流往SWAP寫一遍，導致GC時間超長。

背景

在高并發(fā)下，Java程序的GC問題屬于很典型的一類問題，帶來的影響往往會被進一步放大。不管是「GC頻率過快」還是「GC耗時太長」，由于GC期間都存在Stop The World問題，因此很容易導致服務(wù)超時，引發(fā)性能問題。

事情最初是線上某應(yīng)用垃圾收集出現(xiàn)Full GC異常的現(xiàn)象，應(yīng)用中個別實例Full GC時間特別長，持續(xù)時間約為15~30秒，平均每2周左右觸發(fā)一次；

圖片

JVM參數(shù)配置：

-Xms2048M –Xmx2048M –Xmn1024M –XX:MaxPermSize=512M

圖片

排查過程

分析 GC 日志

GC 日志它記錄了每一次的 GC 的執(zhí)行時間和執(zhí)行結(jié)果，通過分析 GC 日志可以調(diào)優(yōu)堆設(shè)置和 GC 設(shè)置，或者改進應(yīng)用程序的對象分配模式。

這里Full GC的reason是Ergonomics，是因為開啟了UseAdaptiveSizePolicy，jvm自己進行自適應(yīng)調(diào)整引發(fā)的Full GC。

這份日志主要體現(xiàn)GC前后的變化，目前為止看不出個所以然來。

圖片

開啟GC日志，需要添加如下 JVM 啟動參數(shù)：

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/export/log/risk_pillar/gc.log

常見的 Young GC、Full GC 日志含義如下：

圖片

進一步查看服務(wù)器性能指標

獲取到了GC耗時的時間后，通過監(jiān)控平臺獲取到各個監(jiān)控項，開始排查這個時點有異常的指標，最終分析發(fā)現(xiàn)，在5.06分左右（GC的時點），CPU占用顯著提升，而SWAP出現(xiàn)了釋放資源、memory資源增長出現(xiàn)拐點的情況（詳見下圖紅色框，橙色框中的變化是因修改配置導致，后面會介紹，暫且可忽略）

圖片

JVM用到了swap？

是因為GC導致的CPU突然飆升，并且釋放了swap交換區(qū)這部分內(nèi)存到memory？

為了驗證JVM是否用到swap，我們通過檢查proc下的進程內(nèi)存資源占用情況

for i in (cd/proc;ls∣grep"[0?9]"∣awk′0 >100');
do awk '/Swap:/{a=a+2}END{print '"i"',a/1024"M"}' /proc/$i/smaps 2>/dev/null;
done | sort -k2nr | head -10 

# head -10 表示 取出 前10個內(nèi)存占用高的進程 
# 取出的第一列為進程的id 第二列進程占用swap大小

看到確實有用到305MB的swap

圖片

這里簡單介紹下什么是swap?

swap指的是一個交換分區(qū)或文件，主要是在內(nèi)存使用存在壓力時，觸發(fā)內(nèi)存回收，這時可能會將部分內(nèi)存的數(shù)據(jù)交換到swap空間，以便讓系統(tǒng)不會因為內(nèi)存不夠用而導致oom或者更致命的情況出現(xiàn)。

當某進程向OS請求內(nèi)存發(fā)現(xiàn)不足時，OS會把內(nèi)存中暫時不用的數(shù)據(jù)交換出去，放在swap分區(qū)中，這個過程稱為swap out。

當某進程又需要這些數(shù)據(jù)且OS發(fā)現(xiàn)還有空閑物理內(nèi)存時，又會把swap分區(qū)中的數(shù)據(jù)交換回物理內(nèi)存中，這個過程稱為swap in。

為了驗證GC耗時與swap操作有必然關(guān)系，我抽查了十幾臺機器，重點關(guān)注耗時長的GC日志，通過時間點確認到GC耗時的時間點與swap操作的時間點確實是一致的。

進一步查看虛擬機各實例 swappiness 參數(shù)，一個普遍現(xiàn)象是，凡是發(fā)生較長Full GC的實例都配置了參數(shù) vm.swappiness = 30（值越大表示越傾向于使用swap）；而GC時間相對正常的實例配置參數(shù) vm.swappiness = 0（最大限度地降低使用swap）。

swappiness 可以設(shè)置為 0 到 100 之間的值，它是Linux的一個內(nèi)核參數(shù)，控制系統(tǒng)在進行swap時，內(nèi)存使用的相對權(quán)重。

swappiness=0: 表示最大限度使用物理內(nèi)存，然后才是 swap空間
swappiness=100: 表示積極的使用swap分區(qū)，并且把內(nèi)存上的數(shù)據(jù)及時的交換到swap空間里面

圖片

對應(yīng)的物理內(nèi)存使用率和swap使用情況如下

圖片

至此，矛頭似乎都指向了swap。

問題分析

當內(nèi)存使用率達到水位線(vm.swappiness)時，linux會把一部分暫時不使用的內(nèi)存數(shù)據(jù)放到磁盤swap去，以便騰出更多可用內(nèi)存空間；

當需要使用位于swap區(qū)的數(shù)據(jù)時，再將其換回內(nèi)存中，當JVM進行GC時，需要對相應(yīng)堆分區(qū)的已用內(nèi)存進行遍歷；

假如GC的時候，有堆的一部分內(nèi)容被交換到swap空間中，遍歷到這部分的時候就需要將其交換回內(nèi)存，由于需要訪問磁盤，所以相比物理內(nèi)存，它的速度肯定慢的令人發(fā)指，GC停頓的時間一定會非常非常恐怖；

進而導致Linux對swap分區(qū)的回收滯后（內(nèi)存到磁盤換入換出操作十分占用CPU與系統(tǒng)IO），在高并發(fā)/QPS服務(wù)中，這種滯后帶來的結(jié)果是致命的(STW)。

問題解決

至此，答案似乎很清晰，我們只需嘗試把swap關(guān)閉或釋放掉，看看能否解決問題？

如何釋放swap?

設(shè)置vm.swappiness=0（重啟應(yīng)用釋放swap后生效），表示盡可能不使用交換內(nèi)存

方案 a：臨時設(shè)置方案，重啟后不生效

設(shè)置vm.swappiness為0，sysctl vm.swappiness=0
查看swappiness值，cat /proc/sys/vm/swappiness

方案b：永久設(shè)置方案，重啟后仍然生效

vi /etc/sysctl.conf
關(guān)閉交換分區(qū)swapoff –a(前提：首先要保證內(nèi)存剩余要大于等于swap使用量，否則會報Cannot allocate memory！swap分區(qū)一旦釋放，所有存放在swap分區(qū)的文件都會轉(zhuǎn)存到物理內(nèi)存上，可能會引發(fā)系統(tǒng)IO或者其他問題。)

查看當前swap分區(qū)掛載在哪：

圖片

關(guān)停分區(qū)：

圖片

關(guān)閉swap交換區(qū)后的內(nèi)存變化見下圖橙色框，此時swap分區(qū)的文件都轉(zhuǎn)存到了物理內(nèi)存上

圖片

關(guān)閉Swap交換區(qū)后，于2.23再次發(fā)生Full GC，耗時190ms，問題得到解決。

圖片

疑惑

是不是只要開啟了swap交換區(qū)的JVM，在GC的時候都會耗時較長呢？
既然JVM對swap如此不待見，為何JVM不明令禁止使用呢？
swap工作機制是怎樣的？這臺物理內(nèi)存為8g的server，使用了交換區(qū)內(nèi)存（swap），說明物理內(nèi)存不夠使用了，但是通過free命令查看內(nèi)存使用情況，實際物理內(nèi)存似乎并沒有占用那么多，反而Swap已占近1G？

圖片

free：除了buff/cache剩余了多少內(nèi)存

shared：共享內(nèi)存

buff/cache：緩沖、緩存區(qū)內(nèi)存數(shù)（使用過高通常是程序頻繁存取文件）

available：真實剩余的可用內(nèi)存數(shù)

進一步思考

大家可以想想，關(guān)閉交換磁盤緩存意味著什么？

其實大可不必如此激進，要知道這個世界永遠不是非0即1的，大家都會或多或少選擇走在中間，不過有些偏向0，有些偏向1而已。

很顯然，在swap這個問題上，JVM可以選擇偏向盡量少用，從而降低swap影響，要降低swap影響有必要弄清楚Linux內(nèi)存回收是怎么工作的，這樣才能不遺漏任何可能的疑點。

先來看看swap是如何觸發(fā)的？

Linux會在兩種場景下觸發(fā)內(nèi)存回收，一種是在內(nèi)存分配時發(fā)現(xiàn)沒有足夠空閑內(nèi)存時會立刻觸發(fā)內(nèi)存回收；另一種是開啟了一個守護進程（kswapd進程）周期性對系統(tǒng)內(nèi)存進行檢查，在可用內(nèi)存降低到特定閾值之后主動觸發(fā)內(nèi)存回收。

通過如下圖示可以很容易理解，詳細信息參見：http://hbasefly.com/2017/05/24/hbase-linux/

是不是只要開啟了swap交換區(qū)的JVM，在GC的時候都會耗時較長？

筆者去查了一下另外的一個應(yīng)用，相關(guān)指標信息請見下圖。

實名服務(wù)的QPS是非常高的，同樣能看到應(yīng)用了swap，GC平均耗時 576ms，這是為什么呢？

圖片

通過把時間范圍聚焦到發(fā)生GC的某一時間段，從監(jiān)控指標圖可以看到swapUsed沒有任何變化，也就是說沒有swap活動，進而沒有影響到垃級回收的總耗時。

圖片

通過如下命令列舉出各進程swap空間占用情況，很清楚的看到實名這個服務(wù)swap空間占用的較少（僅54.2MB）

圖片

另一個顯著的現(xiàn)象是實名服務(wù)Full GC間隔較短（幾個小時一次），而我的服務(wù)平均間隔2周一次Full GC

圖片

基于以上推測

實名服務(wù)由于 GC 間隔較短，內(nèi)存中的東西根本沒有機會置換到swap中就被回收了，GC的時候不需要將swap分區(qū)中的數(shù)據(jù)交換回物理內(nèi)存中，完全基于內(nèi)存計算，所以要快很多
將哪些內(nèi)存數(shù)據(jù)置換進swap交換區(qū)的篩選策略應(yīng)該是類似于LRU算法（最近最少使用原則）

為了證實上述猜測，我們只需跟蹤swap變更日志，監(jiān)控數(shù)據(jù)變化即可得到答案，這里采用一段shell 腳本實現(xiàn)

#!/bin/bash 
echo -e `date +%y%m%d%H%M%S` 
echo -e "PID\t\tSwap\t\tProc_Name" 

#拿出/proc目錄下所有以數(shù)字為名的目錄（進程名是數(shù)字才是進程，其他如sys,net等存放的是其他信息） 
for pid in `ls -l /proc | grep ^d | awk '{ print $9 }'| grep -v [^0-9]` 
do 
    if [ $pid -eq 1 ];then continue;fi 
    grep -q "Swap" /proc/$pid/smaps 2>/dev/null 
    if [ $? -eq 0 ];then 
        swap=$(gawk '/Swap/{ sum+=$2;} END{ print sum }' /proc/$pid/smaps) #統(tǒng)計占用的swap分區(qū)的 大小 單位是KB 
        proc_name=$(ps aux | grep -w "$pid" | awk '!/grep/{ for(i=11;i<=NF;i++){ printf("%s ",$i); }}') #取出進程的名字 
        if [ $swap -gt 0 ];then #判斷是否占用swap 只有占用才會輸出 
            echo -e "${pid}\t${swap}\t${proc_name:0:100}" 
    fi 
   fi
done | sort -k2nr | head -10 | gawk -F'\t' '{ #排序取前 10 
    pid[NR]=$1; 
    size[NR]=$2; 
    name[NR]=$3; 
} 
END{ 
    for(id=1;id<=length(pid);id++) 
    { 
    if(size[id]<1024) 
        printf("%-10s\t%15sKB\t%s\n",pid[id],size[id],name[id]); 
    else if(size[id]<1048576) 
        printf("%-10s\t%15.2fMB\t%s\n",pid[id],size[id]/1024,name[id]);
    else 
    printf("%-10s\t%15.2fGB\t%s\n",pid[id],size[id]/1048576,name[id]); 
    } 
}

由于上面圖中 2022.3.2 19:57:00 至 2022.3.2 19:58:00 發(fā)生了一次Full GC，我們重點關(guān)注下這一分鐘內(nèi)swap交換區(qū)的變化即可，我這里每10s做一次信息采集，可以看到在GC時點前后，swap確實沒有變化

圖片

通過上述分析，回歸本文核心問題上，現(xiàn)在看來我的處理方式過于激進了，其實也可以不用關(guān)閉swap，通過適當降低堆大小，也是能夠解決問題的。

這也側(cè)面的說明，部署Java服務(wù)的Linux系統(tǒng)，在內(nèi)存分配上并不是無腦大而全，需要綜合考慮不同場景下JVM對Java永久代、Java堆(新生代和老年代)、線程棧、Java NIO所使用內(nèi)存的需求。

總結(jié)

綜上，我們得出結(jié)論，swap和GC同一時候發(fā)生會導致GC時間非常長，JVM嚴重卡頓，極端的情況下會導致服務(wù)崩潰。

主要原因是：JVM進行GC時，需要對對應(yīng)堆分區(qū)的已用內(nèi)存進行遍歷，假如GC的時候，有堆的一部分內(nèi)容被交換到swap中，遍歷到這部分的時候就須要將其交換回內(nèi)存；更極端情況同一時刻因為內(nèi)存空間不足，就需要把內(nèi)存中堆的另外一部分換到SWAP中去，于是在遍歷堆分區(qū)的過程中，會把整個堆分區(qū)輪流往SWAP寫一遍，導致GC時間超長。線上應(yīng)該限制swap區(qū)的大小，如果swap占用比例較高應(yīng)該進行排查和解決，適當?shù)臅r候可以通過降低堆大小，或者添加物理內(nèi)存。

因此，部署Java服務(wù)的Linux系統(tǒng)，在內(nèi)存分配上要慎重。

責任編輯：武曉燕來源： JAVA日知錄