點擊上方“占小狼的博客”，選擇“設為星標

最近熱文

?

• JDK13的 5個新特性，搶先看，開車都追不上了！

• 面試官問，使用Dubbo有沒有遇到一些坑？我笑了。

• 螞蟻面試：字符串在JVM中如何存放？

某天上午收到最近發布的一個服務頻繁FGC的告警，這個服務只是給公司內部相關人員使用的，并非給互聯網用戶提供服務的系統。而且功能也比較簡單，就是查看一些統計信息、報表數據、數據導出Excel等，訪問量非常低。

另外，由于這個服務并不是OLTP，所以就是簡單的使用默認的ParallGC垃圾回收器，JVM參數也只是做了簡單的配置：

-Xmx512m?-Xms512m?-Xmn256m?XX:+PrintGCDetails??-XX:+PrintGCDateStamps?

關鍵線索

廢話不多說，既然有FGC，那就首先查看GC日志。畢竟FGC的原因還是比較多的，GC日志也是最直觀的展示FGC原因的證據之一。

這里要補充一句，我們在排查問題時，切記不要靠自己的主觀意識猜測，而應該做到每一步的推斷都有理有據，這樣才能越來越接近真相，找出真正的兇手。

GC日志中尋找FGC的命令以及結果如下所示(只貼出部分)：

afeideMacBook-Pro:jvm afei$ grep "full gc" -i gc.log

2019-06-15T09:35:04.168-0800: [Full GC (System.gc()) [PSYoungGen: 6963K->0K(229376K)] [ParOldGen: 8K->6793K(262144K)] 6971K->6793K(491520K), [Metaspace: 5160K->5160K(1056768K)], 0.0085889 secs] [Times: user=0.03 sys=0.01, real=0.01 secs]

2019-06-15T09:40:08.520-0800: [Full GC (System.gc()) [PSYoungGen: 5184K->0K(229376K)] [ParOldGen: 6793K->6090K(262144K)] 11977K->6090K(491520K), [Metaspace: 5168K->5168K(1056768K)], 0.0085573 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]

... ...

根據這段GC日志就能非常肯定：是因為某些地方調用System.gc()觸發的FGC。

因為這個服務訪問亮比較小，并發量并不高。所以，筆者想看看觸發FGC的時候，服務被調用了什么接口(如果是并發很高的OLTP，這種方法可能就不是很適用，畢竟每秒TPS成百上千，甚至更大，根本無法確定是哪個接口引起的)。

以上面這段FGC日志，根據其觸發的時間點，然后去系統業務日志中查找。很順利我們就找到了這個時候是調用了一個導出報表數據到Excel并下載的接口。一開始我還有點懷疑會不會是導出數據量很大引起FGC，但是后面走讀業務代碼，發現導出數據限制最大不超過1000，所以，這個猜想也就被否定了。

重現問題

既然是導出Excel引起的，那么筆者就打算模擬這段代碼，試圖以最小量的代碼看是否能重現這個問題。畢竟：范圍越小，距離真相也就越近。

所以，筆者根據這個接口的業務代碼，等價的寫出了下面這段代碼：

public class JxlTest {

public static void main(String[] args) throws Exception {

for (int i = 0; i < 10; i++) {

excelGen();

}

}

private static void excelGen() throws Exception {

WritableWorkbook book = null;

WritableSheet sheet;

try {

book = Workbook.createWorkbook(new File("/Users/litian/afei.xls"));

sheet = book.createSheet("PageNo.1", 0);

Label label = new Label(0, 0, "公眾號：【阿飛的博客】");

sheet.addCell(label);

book.write();

} catch (Exception e) {

e.printStackTrace();

} finally {

book.close();

}

}

}

配套的JVM參數如下，接下來運行這段代碼即可。過程是如此順利，10次Excel操作，10次FGC：

-XX:+PrintGCDateStamps -XX:+PrintGCDetails

-Xmx512m -Xms512m -Xmn256m

-verbose:gc

之所以用這段JVM參數，是為了希望通過-verbose:gc將GC日志直接輸出到idea的控制臺，而不是將GC日志輸出到GC日志文件中，這樣更方便定位問題。而且這段JVM參數相比生產環境的JVM參數，堆的大小和比例都是一樣的，垃圾回收器也都是默認的。

既然重現問題了，那就相當于問題解決了一半。竊喜，哈哈哈～～～

另辟蹊徑

事實上定位這種問題最常見的方法還是借助btrace跟蹤是哪里調用了System.gc()，畢竟，如果不能像筆者這種場景用一段很小的代碼重現問題，筆者接下來介紹的方法可行性就不是很高。但是既然重現了，那么筆者今天就介紹另外一個門檻更低的辦法：借助IDEA強大的搜索功能。畢竟定位問題不是為了炫技，只要能找出問題的辦法，都是好辦法。

需要說明的，這段代碼筆者是在一個新建的Maven工程中運行的，這段代碼只依賴了一個jxl。之所以這么做，是為了筆者接下來介紹的方法能更精確的定位問題所在：

net.sourceforge.jexcelapi

jxl

2.6.12

接下來就是筆者介紹的方法：如何通過牛逼的IDEA找出是哪里調用了System.gc()。在搜索觸發FGC的元兇之前，需要先下載jxl的源碼--這段重現問題源碼唯一的Maven依賴。這個下載必不可少，否則IDEA是無法搜到的：

jxl源碼下載完成后，就是打開IDEA強大的搜索了，由于有些同學是Window，有些同學是Mac，快捷鍵可能不同。所以筆者不介紹打開這個搜索功能的快捷鍵，而是介紹打開這個搜索功能的路徑：

#?這里是Find?in?Path，而不是FindEdit->Find->Find?in?Path?#?范圍選擇Scope->Custom->Project?and?Libraries

需要再次強調，一定要先通過idea下載jxl的源碼，否則 FindinPath是搜不到項目依賴的jxl中的內容。如下圖所示，只能搜到jdk源碼中哪些地方調用了System.gc()：

如果jxl源碼下載后， FindinPath中選擇范圍 ProjectandLibraries后搜索 System.gc()的結果應該如下所示，紅色框中就是依賴的開源組件jxl調用System.gc的地方：

現在范圍就很小很小了，經過代碼排查，我們很快就發現是在調用WritableWorkbook的close()方法時調用了System.gc()，從而觸發了FGC。

很多同學可能會想到通過JVM參數-XX:+DisableExplicitGC來屏蔽掉System.gc()的調用，這不是解決問題，而是掩蓋問題。而且事實上，這里還有更好的辦法，請繼續往下看。

解決方案

我們排查jxl中所有調用System.gc()的地方，發現都是下面這種姿勢。Bingo，那么我們只需要將workbookSettings中gcDisabled這個字段的值設置為true就不會調用System.gc了：

if (!workbookSettings.getGCDisabled()) {

System.gc();

}

gcDisabled設置為true非常簡單，只需要稍微改造一下Workbook.createWorkbook()即可：

WorkbookSettings settings = new WorkbookSettings();

settings.setGCDisabled(true);

book = Workbook.createWorkbook(new File("/Users/litian/afei.xls"), settings);

代碼改造后再次執行，再也不會有調用System.gc觸發FGC了。美滋滋呀～～

需要說明的是，最后還需要對這段代碼進行壓測，不斷循環調用，看看是否GC異常，或者有堆外內存泄漏的情況(堆外內存只升不降)。

幸運的是，沒有任何問題。開心！

最后，分享一份面試寶典《Java核心知識點整理.pdf》，覆蓋了JVM、鎖、高并發、反射、Spring原理、微服務、Zookeeper、數據庫、數據結構等等。

獲取方式：點“好看”，關注公眾號并回復?666 領取，更多內容陸續奉上。

明天見(｡･ω･｡)ﾉ?

總結

以上是生活随笔為你收集整理的idea启动日志在哪里_牛逼了！用 IDEA 扒出了开源组件导致FGC的原因的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。