問題描述
應用收到頻繁Full GC告警
問題排查
登入到對應機器上去，檢視GC日志，發現YGC一分鐘已經達到了15次，比Full GC還要頻繁一些，其中Full GC平均10分鐘超過了4次，如下圖
使用jstat -gcutil 5280 1000檢視實時GC情況，年老代采用的是CMS收集器，發現觸發Full GC的原因是年老代占用空間達到指定門檻值70%(-XX:CMSInitiatingOccupancyFraction=70)。
這時候猜測是某個地方頻繁建立對象導緻，通過jmap -dump:format=b,file=temp.dump 5280 dump檔案，然後下載下傳到本地通過jvisualvm分析對象的引用鍊的方式來定位具體頻繁建立對象的地方，dump檔案下載下傳下來有5G多，整個導入過程都花了10多分鐘。想檢視所占空間較多對象的引用鍊，直接OOM了，dump對象太大了。這時候就換了種思路，檢視占用空間比較大的一系列對象，看能不能找出什麼端倪。占用空間最大的幾類對象如下圖
發現排第一的chart[]對象裡面，存在一些metrics監控的具體名額的相關内容，排第二的io.prometheus.client.Collector$MetricFamilySample$Sample和排第9和第13對象都是spring boot中metrics名額監控相關的對象，是以此時懷疑metrics監控的某個地方在頻繁建立對象，首先考慮的是否因為metrics名額太多導緻的，于是登入線上機器curl localhost:8080/mertrics > metrics.log，發現響應内容有50多M，參考其他相關的正常應用，名額總共内容也就10多M左右，打開名額内容發現了很多類似如下圖的名額
看到了這裡已經可以确定代碼中上報這個名額是存在問題的，并沒有達到我們想要的效果，是以也懷疑也是這個地方導緻的Full GC頻繁。
問題初步解決
由于這個名額也無關緊要，初步解決方案就把上報該名額的代碼給幹掉。上線後看下Full GC問題是否會得到改善，果然，上線後Full GC告警問題已經解決。
初步解決後的思考，為什麼會有這個問題？
外部監控系統，每25s會來調用metrics這個接口，這個接口會把所有的metrics名額轉成字元串然後作為http響應内容響應。監控每來調用一次就會産生一個50多M的字元串，導緻了頻繁YGC，進而導緻了晉升至年老代的對象也多了起來，最終年老代記憶體占用達到70%觸發了Full GC。
根源問題重制
此處采用metrics的作用：統計線程池執行各類任務的數量。為了簡化代碼，用一個map來統計，重制代碼如下
import java.util.Map;
import java.util.concurrent.*;
import java.util.concurrent.atomic.AtomicInteger;
public class GCTest {
private static Map metricsMap = new ConcurrentHashMap<>();
public static void main(String[] args) throws InterruptedException {
ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(10, 10, 0, TimeUnit.SECONDS, new LinkedBlockingQueue<>()){
@Override
protected void afterExecute(Runnable r, Throwable t) {
super.afterExecute(r, t);
metricsMap.compute(r.toString(), (s, atomicInteger) ->
new AtomicInteger(atomicInteger == null ? 0 : atomicInteger.incrementAndGet()));
}
};
for (int i =0; i < 1000; i++) {
threadPoolExecutor.submit(new SimpleRunnable());
}
Thread.sleep(1000 * 2);
System.out.println(metricsMap);
threadPoolExecutor.shutdownNow();
}
static class SimpleRunnable implements Runnable{
@Override
public void run() {
System.out.println("SimpleRunnable execute success");
}
@Override
public String toString(){
return this.getClass().getSimpleName();
}
}
}
最終解決
可以把submit改成execute即可
總結
以上重顯代碼可以看出metricsMap中的元素是會越來越多的。如果就這樣下去，最終的結果也會出現OOM。
根本原因還是對ThreadPoolExecutor不夠熟悉，是以出現了這次問題。
個人感覺Full GC類問題是比較讓人頭疼的。這些問題并不會想代碼文法問題一樣，ide會提示我們具體錯在哪裡，我們隻要修改對應地方基本都能解決。造成Full GC頻繁的原因也有很多，比如可能是jvm參數設定不合理、Metaspace空間觸發、頻繁建立對象觸發等等。
如果确定了是頻繁建立對象導緻，那麼接下來的目的就是确定頻繁建立對象的對應代碼處，這時候可以選擇通過dump線上堆棧，然後下載下傳到本地。選擇一些可視化分析工具進行分析。最終定位到出問題的代碼處，然後解決問題。
版權聲明 作者：wycm
出處：https://my.oschina.net/wycm/blog/3023954
您的支援是對部落客最大的鼓勵，感謝您的認真閱讀。
本文版權歸作者所有，歡迎轉載，但未經作者同意必須保留此段聲明，且在文章頁面明顯位置給出原文連接配接，否則保留追究法律責任的權利。