實戰:IDEA運行速度調優


序言

可能大家覺得系統調優一般都是針對服務端應用而言的,普通Java開發人員很少有機會實踐。今天就通用一個Java開發人員日常工作中經常使用的開發工具開做一次調優實戰。

我在日常工作中的主要IDE工具是IntelliJ IDEA,由於安裝的插件較多,項目代碼也比很多,所以運行速度不是特別令人滿意,所以決定對其進行調優。

IDEA的運行平台是64位Windows10系統,虛擬機為HotSpot 1.8 b64。硬件為Intel i7-10510U,8GB物理內存。

 

初始JVM參數配置如下:

1 -Xmx512m
2 -XX:ReservedCodeCacheSize=240m
3 -XX:SoftRefLRUPolicyMSPerMB=80
4 -ea
5 -Dsun.io.useCanonCaches=false
6 -Djava.net.preferIPv4Stack=true
7 -XX:+HeapDumpOnOutOfMemoryError
8 -XX:-OmitStackTraceInFastThrow

 

為了方便與調優后的結果做對比,在開始前先做一組初始數據測試。

由於無法得知IDEA啟動的准確耗時,我們通過VisualGC收集到的信息,總結初始配置下的測試結果:

最后一次啟動的數據樣本中,垃圾收集總耗時3.102秒,其中:

  • FULL GC被觸發了6次,共耗時1.109秒。
  • Minor GC被觸發了89次,共耗時1.933秒。
  • 加載類41148個,耗時28.908秒。 
  • 虛擬機的512MB堆內存被分配為50MB的新生代(40MB的Eden區和兩個5MB的Survivor區)和462MB的老年代。

                                                     圖:VisualVM監控

 

1、編譯時間和類加載優化

  通過測試數據可以看到,加載類和編譯的時間非常耗時,而在其中字節碼校驗耗時占較大的比例。IDEA作為一款廣為使用的成熟產品,它的編譯代碼我們可以認為是安全可靠的,不需要在加載過程中再進行字節碼驗證,因此可以通過-Xverify:none參數禁止掉字節碼校驗過程。

                                                     圖:類的生命周期

在加入這個參數后,類的加載速度得到了一定的提升,加載時間縮減到19秒左右。

 

2、調整內存設置控制垃圾收集頻率

  下面我們要對“GC時間”進行調整優化,“GC時間”是最為重要的一塊,這不單單是因為它消耗的時間較長,而是因為垃圾回收是一個穩定而持續的過程。在當前的測試用例中,加載類和即使編譯的時間所占比例看上去比較高,但是在絕大多數的應用中,不可能出現持續的類加載和卸載過程。程序在運行了一段時間后,隨着熱點方法被不斷的編譯,新的熱點方法數量也會下降,這會讓類加載和即時編譯所占的時間比例隨着運行時間的增加而逐漸下降。但是垃圾回收卻是隨着程序運行而持續運作的,所以它才是對性能影響最重要的部分。

  從測試的樣本中來看,在IDEA啟動過程中,共發生了6次FULL GC和89次Minor GC,一共95次GC造成了約3秒的停頓。

  首先來分析新生代的Minor GC,盡管垃圾收集時間只有不到2秒,但是發生了89次之多。由於每次垃圾回收都需要用戶線程跑到最近的安全點然后掛起來等待垃圾回收,頻繁的垃圾收集必然會導致很多沒有必要的線程掛起和恢復動作。

  新生代垃圾收集頻繁很明顯是由於虛擬機分配的新生代空間太小導致的,Eden區加上一個Survivor區才45MB。所以我們通過-Xmn參數指定新生代大小為128MB。

  再來看那6次FULL GC,雖然觸發次數較少,但是平均每次的耗時要比較於Minor GC要高的多,所以降低垃圾收集的停頓時間的主要目標就是要降低FULL GC時間。我們從GC日志中分析得到FULL GC的原因,從GC日志中截取FULL GC部分日志。

 1 [Full GC (Metadata GC Threshold) 2020-05-23T14:55:15.403+0800: 4.363: [Tenured: 56560K->54011K(77824K), 0.0691307 secs] 71164K->54011K(123904K), [Metaspace: 34482K->34482K(1081344K)], 0.0692415 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
 2 
 3 [Full GC (Metadata GC Threshold) 2020-05-23T14:55:15.403+0800: 4.363: [Tenured: 56560K->54011K(77824K), 0.0691307 secs] 71164K->54011K(123904K), [Metaspace: 34482K->34482K(1081344K)], 0.0692415 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
 4 
 5 [Full GC (Metadata GC Threshold) 2020-05-23T14:55:17.319+0800: 6.279: [Tenured: 67919K->65602K(90020K), 0.1222525 secs] 78376K->65602K(136100K), [Metaspace: 55927K->55927K(1099776K)], 0.1224057 secs] [Times: user=0.13 sys=0.00, real=0.12 secs]
 6 
 7 [Full GC (Metadata GC Threshold) 2020-05-23T14:55:19.520+0800: 8.480: [Tenured: 81857K->76282K(109340K), 0.1617177 secs] 105366K->76282K(155420K), [Metaspace: 91958K->91958K(1132544K)], 0.1618629 secs] [Times: user=0.19 sys=0.00, real=0.16 secs]
 8 
 9 [GC (Allocation Failure) 2020-05-23T14:55:29.399+0800: 18.360: [DefNew: 46080K->3039K(46080K), 0.0338515 secs]2020-05-23T14:55:29.433+0800: 18.394: [Tenured: 129641K->112262K(129828K), 0.3193513 secs] 170759K->112262K(175908K), [Metaspace: 147845K->147845K(1183744K)], 0.3535963 secs] [Times: user=0.36 sys=0.00, real=0.35 secs]
10 
11 [GC (Allocation Failure) 2020-05-23T14:55:40.032+0800: 28.992: [DefNew: 46080K->5120K(46080K), 0.0528825 secs]2020-05-23T14:55:40.085+0800: 29.044: [Tenured: 198033K->176461K(198052K), 0.4157306 secs] 231627K->176461K(244132K), [Metaspace: 194691K->194691K(1224704K)], 0.4690424 secs] [Times: user=0.48 sys=0.00, real=0.47 secs]

 

    日志中加粗的部分代表着老年代的容量,幾乎每一次FULL GC的原因都是老年代空間耗盡,每一次FULL GC都伴隨着老年代空間的擴容:77824K → 90020K → 109340K → 129828K → 198052K。

  日志中還顯示有些時候內存回收效果不理想,空間擴容成了獲取可用內存的最主要手段,比如這一句:[Tenured: 81857K->76282K(109340K), 0.1617177 secs]

  代表在老年代當前容量為109340KB,內存使用到81857K時發生了FULL GC,花費了0.3193513秒時間把內存使用降低到76282K,回收了5575KB的內存空間。但是這次垃圾回收未達到效果,觸發了空間擴容。擴容相比起回收過程可以看做基本不需要花費時間,所以這0.3193513秒時間幾乎是浪費了。

  由上述分析可以得到一個結論,FULL GC大多數是由於老年代容量擴展而導致的。那怎樣避免擴容時的性能浪費呢,可以把-Xms參數設置為-Xmx參數值一樣。將堆棧的空間固定下來,避免了運行時的自動擴展。

  由於元空間(Metaspace)的擴展也占據了一部分的垃圾收集時間,我們可以通過設置一個元空間初始值來避免掉一部分擴展。(由於元空間的默認最大值是不受限制的,即只受限於本地內存大小,故只調整初始空間大小)

注:截取的GC日志,顯示元空間的擴展也消耗了部分GC時間。

[Metaspace: 55927K->55927K(1099776K)], 0.1224057 secs]
[Metaspace: 91958K->91958K(1132544K)], 0.1618629 secs]

 

根據以上的分析,優化方案如下:

  • 新生代空間提升到128MB(-Xmn128m)
  • Java堆容量固定為512MB(-Xms512m、-Xmx512m)
  • 元空間容量初始值設置為(-XX:MetaspaceSize=250m)

調整后的JVM配置

1 -Xms512m
2 -Xmx512m
3 -Xmn128m
4 -XX:MetaspaceSize=250m
5 -Xverify:none

 

在這個配置下再次測試,垃圾收集的次數已經大幅降低,只發生了34次Minor GC和1次FULL GC,總耗時1.823秒。

                                        圖:調整后的JVM運行數據

    從結果看,優化效果很明顯,但是有一點疑問,從Old Gen的曲線上來看,老年代的空間直接固定在384MB,而內存使用量還不足以觸發FULL GC。那一次FULL GC是怎么來的呢?查看GC日志來查明原因。

1 2020-05-23T16:02:56.546+0800: 21.430: [Full GC (System.gc()) 2020-05-23T16:02:56.546+0800: 21.430: [Tenured: 160328K->152291K(393216K), 0.4226741 secs] 221862K->152291K(511232K), [Metaspace: 143107K->143107K(1181696K)], 0.4228607 secs] [Times: user=0.42 sys=0.00, real=0.42 secs]

    原來是代碼中顯示的調用了System.gc()觸發了垃圾收集,在內存設置調整后,這種顯式的垃圾收集不符合我們的期望。在JVM參數中加入-XX:DisableExplicitGC屏蔽掉System.gc()。

 

3、選擇收集器降低延遲

  通過查看啟動期間的CPU使用情況,我們可以看到CPU的平均使用率並不高,垃圾收集的處理器使用率就更低了,幾乎和橫坐標緊貼在一起。這說明處理器資源還很富足。

    Java虛擬機提供了多種垃圾收集器的組合,很容易想到CMS是最符合當前場景的選擇。

 在JVM配置中加入這兩個參數:

 -XX:+UseParNewGC、-XX:+UseConcMarkSweepGC;

 要求虛擬機在新生代和老年代分別使用ParNew和CMS收集器來進行垃圾回收。

             圖:指定ParNew和CMS收集器后的GC數據

 

    再次測試后,新生代停頓553毫秒,老年代停頓96毫秒,總耗時降低為649毫秒。相比較於調整垃圾收集器前快了將近三倍之多。

 當然,由於CMS的停頓時間只是整個收集過程中的一小部分,大部分收集行為都是和用戶線程並發執行的。所以這里並不是真的將收集時間降低到649毫秒了。

 到此為止,對於IDEA的JVM調優就結束了,我們終於可以愉快的使用IDEA進行工作了!最終的配置清單如下所示。

 1 # custom IntelliJ IDEA VM options
 2 -Xms512m
 3 -Xmx512m
 4 -Xmn128m
 5 -XX:MetaspaceSize=250m
 6 -Xverify:none
 7 -XX:+UseParNewGC
 8 -XX:+UseConcMarkSweepGC
 9 -XX:CMSInitiatingOccupancyFraction=85
10 -XX:+DisableExplicitGC-XX:ReservedCodeCacheSize=240m
11 -XX:SoftRefLRUPolicyMSPerMB=80
12 -ea
13 -Dsun.io.useCanonCaches=false
14 -Djava.net.preferIPv4Stack=true
15 -XX:+HeapDumpOnOutOfMemoryError
16 -XX:-OmitStackTraceInFastThrow

鏈接: 文章首發地址


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM