JVM調優筆記
JVM引數調優整理
1.調優工具
JVisualVM 和 JConsole
以上兩個工具都是JDK自帶的，在JDK安裝目錄下就可以找到對應的exe可執行檔案
通過 JVisualVM 連線到某個JVM以後, 切換到 MBeans 標籤, 展開 “java.lang/GarbageCollector” . 就可以看到GC行為資訊, 下圖是 JVisualVM 中的截圖:
下圖是Java Mission Control 中的截圖:
從以上截圖中可以看到兩款垃圾收集器。其中一款負責清理年輕代(PS Scavenge)，另一款負責清理老年代(PS MarkSweep); 列表中顯示的就是垃圾收集器的名稱。可以看到 , jmc 的功能和展示資料的方式更強大
對所有的垃圾收集器, 通過 JMX API 獲取的資訊包括:
CollectionCount : 垃圾收集器執行的GC總次數,
CollectionTime: 收集器執行時間的累計。這個值等於所有GC事件持續時間的總和,
LastGcInfo: 最近一次GC事件的詳細資訊。包括 GC事件的持續時間(duration), 開始時間(startTime) 和 結束時間(endTime), 以及各個記憶體池在最近一次GC之前和之後的使用情況,
MemoryPoolNames: 各個記憶體池的名稱,
Name: 垃圾收集器的名稱
ObjectName: 由JMX規範定義的 MBean的名字,
Valid: 此收集器是否有效。本人只見過 “true“的情況 (^_^)
根據經驗, 這些資訊對GC的效能來說,不能得出什麼結論. 只有編寫程式, 獲取GC相關的 JMX 資訊來進行統計和分析。 在下文可以看到, 一般也不怎麼關注 MBean , 但 MBean 對於理解GC的原理倒是挺有用的。
JVisualVM
Visual GC 外掛常用來監控本機執行的Java程式, 比如開發者和效能調優專家經常會使用此外掛, 以快速獲取程式執行時的GC資訊
左側的圖表展示了各個記憶體池的使用情況: Metaspace/永久代, 老年代, Eden區以及兩個存活區。
在右邊, 頂部的兩個圖表與 GC無關, 顯示的是 JIT編譯時間 和 類載入時間。下面的6個圖顯示的是記憶體池的歷史記錄, 每個記憶體池的GC次數,GC總時間, 以及最大值，峰值, 當前使用情況。
jstat
jstat 也是標準JDK提供的一款監控工具(Java Virtual Machine statistics monitoring tool),可以統計各種指標。既可以連線到本地JVM,也可以連到遠端JVM. 檢視支援的指標和對應選項可以執行 “jstat -options” 。例如:
| Option | Displays |
|---|---|
| class | Statistics on the behavior of the class loader |
| compiler | Statistics on the behavior of the HotSpot Just-In-Time com |
| piler | |
| gc | corresponding spaces. |
| gccapacity | Summary of garbage collection statistics (same as -gcutil), |
| with the cause of the last and current (if applicable) | |
| garbage collection events. | |
| gcnew | Statistics of the behavior of the new generation. |
| gcnewcapacity | Statistics of the sizes of the new generations and its corre- |
| gcold | sponding spaces. |
| Statistics of the behavior of the old and permanent genera | |
| tions. | |
| gcoldcapacity | Statistics of the sizes of the old generation. |
| gcpermcapacity | Statistics of the sizes of the permanent generation. |
| gcutil | Summary of garbage collection statistics. |
| printcompilation | Summary of garbage collection statistics. |
jstat 對於快速確定GC行為是否健康非常有用。啟動方式為: “jstat -gc -t PID 1s” , 其中,PID 就是要監視的Java程序ID。可以通過 jps 命令檢視正在執行的Java程序列表。
jps
jstat -gc -t 2428 1s以上命令的結果, 是 jstat 每秒向標準輸出輸出一行新內容, 比如:
稍微解釋一下上面的內容。參考 jstat manpage , 我們可以知道:
- - jstat 連線到 JVM 的時間, 是JVM啟動後的 200秒。此資訊從第一行的 “Timestamp” 列得知。繼續看下一行, jstat 每秒鐘從JVM 接收一次資訊, 也就是命令列引數中 “1s” 的含義
- - 從第一行的 “YGC” 列得知年輕代共執行了34次GC, 由 “FGC” 列得知整個堆記憶體已經執行了 658次 full GC
- - 年輕代的GC耗時總共為 0.720 秒, 顯示在“YGCT” 這一列
- - Full GC 的總計耗時為 133.684 秒, 由“FGCT”列得知。 這立馬就吸引了我們的目光, 總的JVM 執行時間只有 200 秒, 但其中有 66% 的部分被 Full GC 消耗了
再看下一行, 問題就更明顯了。
- - 在201秒的時候，一秒內共執行了 4 次 Full GC。參見 “FGC” 列
- - 這4次 Full GC 暫停佔用了差不多 1秒的時間(根據 FGCT列的差得知)。與第一行相比, Full GC 耗費了928 毫秒, 即 92.8% 的時間
- - 根據 “OC 和 “OU” 列得知, 整個老年代的空間為 169,344.0 KB (“OC“), 在 4 次 Full GC 後依然佔用了 169,344.2 KB (“OU“)。用了 928ms 的時間卻只釋放了 800 位元組的記憶體, 怎麼看都覺得很不正常
只看這兩行的內容, 就知道程式出了很嚴重的問題。繼續分析下一行, 可以確定問題依然存在,而且變得更糟
JVM幾乎完全卡住了(stalled), 因為GC佔用了90%以上的計算資源。GC之後, 所有的老代空間仍然還在佔用。事實上, 程式在一分鐘以後就掛了, 丟擲了 “java.lang.OutOfMemoryError: GC overhead limit exceeded” 錯誤
可以看到, 通過 jstat 能很快發現對JVM健康極為不利的GC行為。一般來說, 只看 jstat 的輸出就能快速發現以下問題
- - 最後一列 “GCT”, 與JVM的總執行時間 “Timestamp” 的比值, 就是GC 的開銷。如果每一秒內, “GCT” 的值都會明顯增大, 與總執行時間相比, 就暴露出GC開銷過大的問題. 不同系統對GC開銷有不同的容忍度, 由效能需求決定, 一般來講, 超過 10% 的GC開銷都是有問題的
- - “YGC” 和 “FGC” 列的快速變化往往也是有問題的徵兆。頻繁的GC暫停會累積,並導致更多的執行緒停頓(stop-the-world pauses), 進而影響吞吐量
- - 如果看到 “OU” 列中,老年代的使用量約等於老年代的最大容量(OC), 並且不降低的話, 就表示雖然執行了老年代GC, 但基本上屬於無效GC
2.GC日誌(GC logs)
通過日誌內容也可以得到GC相關的資訊。因為GC日誌模組內置於JVM中, 所以日誌中包含了對GC活動最全面的描述。 這就是事實上的標準, 可作為GC效能評估和優化的最真實資料來源
GC日誌一般輸出到檔案之中, 是純 text 格式的, 當然也可以列印到控制檯。有多個可以控制GC日誌的JVM引數。例如,可以列印每次GC的持續時間, 以及程式暫停時間(-XX:+PrintGCApplicationStoppedTime), 還有GC清理了多少引用型別(-XX:+PrintReferenceGC)
要列印GC日誌, 需要在啟動指令碼中指定以下引數:
-XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:<filename>以上引數指示JVM: 將所有GC事件列印到日誌檔案中, 輸出每次GC的日期和時間戳。不同GC演算法輸出的內容略有不同
ParallelGC 輸出的日誌類似這樣:
分析以上日誌內容, 可以得知:
- - 這部分日誌擷取自JVM啟動後200秒左右
- - 日誌片段中顯示, 在780毫秒以內, 因為垃圾回收 導致了5次 Full GC 暫停(去掉第六次暫停,這樣更精確一些)
- - 在GC完成之後, 幾乎所有的老年代空間(169,472 KB)依然被佔用(169,318 KB)
通過日誌資訊可以確定, 該應用的GC情況非常糟糕。JVM幾乎完全停滯, 因為GC佔用了超過99%的CPU時間。 而GC的結果是, 老年代空間仍然被佔滿, 這進一步肯定了我們的結論。 示例程式和jstat 小節中的是同一個, 幾分鐘之後系統就掛了, 丟擲 “java.lang.OutOfMemoryError: GC overhead limit exceeded” 錯誤, 不用說, 問題是很嚴重的
從此示例可以看出, GC日誌對監控GC行為和JVM是否處於健康狀態非常有用。一般情況下, 檢視 GC 日誌就可以快速確定以下症狀:
- - GC開銷太大。如果GC暫停的總時間很長, 就會損害系統的吞吐量。不同的系統允許不同比例的GC開銷, 但一般認為, 正常範圍在 10% 以內
- - 老年代的使用量超過限制。如果老年代空間在 Full GC 之後仍然接近全滿, 那麼GC就成為了效能瓶頸, 可能是記憶體太小, 也可能是存在記憶體洩漏。這種症狀會讓GC的開銷暴增
- - 極個別的GC事件暫停時間過長。當某次GC暫停時間太長, 就會影響系統的延遲指標. 如果延遲指標規定交易必須在 1,000 ms內完成, 那就不能容忍任何超過 1000毫秒的GC暫停
3.高分配速率(High Allocation Rate)
分配速率(Allocation rate)表示單位時間內分配的記憶體量。通常使用 MB/sec作為單位, 也可以使用 PB/year 等。
分配速率過高就會嚴重影響程式的效能。在JVM中會導致巨大的GC開銷。
如何測量分配速率?
指定JVM引數: -XX:+PrintGCDetails -XX:+PrintGCTimeStamps , 通過GC日誌來計算分配速率. GC日誌如下所示:
0.291: [GC (Allocation Failure)
[PSYoungGen: 33280K->5088K(38400K)]
33280K->24360K(125952K), 0.0365286 secs]
[Times: user=0.11 sys=0.02, real=0.04 secs]
0.446: [GC (Allocation Failure)
[PSYoungGen: 38368K->5120K(71680K)]
57640K->46240K(159232K), 0.0456796 secs]
[Times: user=0.15 sys=0.02, real=0.04 secs]
0.829: [GC (Allocation Failure)
[PSYoungGen: 71680K->5120K(71680K)]
112800K->81912K(159232K), 0.0861795 secs]
[Times: user=0.23 sys=0.03, real=0.09 secs]計算 上一次垃圾收集之後,與下一次GC開始之前的年輕代使用量, 兩者的差值除以時間,就是分配速率。 通過上面的日誌, 可以計算出以下資訊:
- - JVM啟動之後 291ms, 共建立了 33,280 KB 的物件。 第一次 Minor GC(小型GC) 完成後, 年輕代中還有 5,088 KB 的物件存活。
- - 在啟動之後 446 ms, 年輕代的使用量增加到 38,368 KB, 觸發第二次GC, 完成後年輕代的使用量減少到 5,120 KB。
- - 在啟動之後 829 ms, 年輕代的使用量為 71,680 KB, GC後變為 5,120 KB。
可以通過年輕代的使用量來計算分配速率, 如下表所示:
4.分配速率的意義
分配速率的變化,會增加或降低GC暫停的頻率, 從而影響吞吐量。 但只有年輕代的 minor GC 受分配速率的影響, 老年代GC的頻率和持續時間不受 分配速率(allocation rate)的直接影響, 而是受到 提升速率(promotion rate)的影響, 請參見下文
現在我們只關心 Minor GC 暫停, 檢視年輕代的3個記憶體池。因為物件在 Eden區分配, 所以我們一起來看 Eden 區的大小和分配速率的關係. 看看增加 Eden 區的容量, 能不能減少 Minor GC 暫停次數, 從而使程式能夠維持更高的分配速率。
經過我們的實驗, 通過引數 -XX:NewSize、 -XX:MaxNewSize 以及 -XX:SurvivorRatio 設定不同的 Eden 空間, 運行同一程式時, 可以發現:
- - Eden 空間為 100 MB 時, 分配速率低於 100 MB/秒
- - 將 Eden 區增大為 1 GB, 分配速率也隨之增長,大約等於 200 MB/秒
為什麼會這樣? —— 因為減少GC暫停,就等價於減少了任務執行緒的停頓，就可以做更多工作, 也就建立了更多物件, 所以對同一應用來說, 分配速率越高越好
在得出 “Eden區越大越好” 這個結論前, 我們注意到, 分配速率可能會,也可能不會影響程式的實際吞吐量。 吞吐量和分配速率有一定關係, 因為分配速率會影響 minor GC 暫停, 但對於總體吞吐量的影響, 還要考慮 Major GC(大型GC)暫停, 而且吞吐量的單位不是 MB/秒， 而是系統所處理的業務量。
5.高分配速率對JVM的影響
首先，我們應該檢查程式的吞吐量是否降低。如果建立了過多的臨時物件, minor GC的次數就會增加。如果併發較大, 則GC可能會嚴重影響吞吐量
遇到這種情況時, GC日誌將會像下面這樣，當然這是上面的示例程式 產生的GC日誌。 JVM啟動引數為
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xmx32m
很顯然 minor GC 的頻率太高了。這說明建立了大量的物件。另外, 年輕代在 GC 之後的使用量又很低, 也沒有 full GC 發生。 種種跡象表明, GC對吞吐量造成了嚴重的影響 **
解決方案
在某些情況下,只要增加年輕代的大小, 即可降低分配速率過高所造成的影響。增加年輕代空間並不會降低分配速率, 但是會減少GC的頻率。如果每次GC後只有少量物件存活, minor GC 的暫停時間就不會明顯增加
執行 示例程式 時, 增加堆記憶體大小,(同時也就增大了年輕代的大小), 使用的JVM引數為 -Xmx64m:
但有時候增加堆記憶體的大小,並不能解決問題。通過前面學到的知識, 我們可以通過分配分析器找出大部分垃圾產生的位置。實際上在此示例中, 99%的物件屬於 Double 包裝類, 在readSensor 方法中建立。最簡單的優化, 將建立的 Double 物件替換為原生型別 double, 而針對 null 值的檢測, 可以使用 Double.NaN 來進行。由於原生型別不算是物件, 也就不會產生垃圾, 導致GC事件。優化之後, 不在堆中分配新物件, 而是直接覆蓋一個屬性域即可 **
對示例程式進行[簡單的改造](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/gc/FixedBoxing.java)( [檢視diff](https://gist.github.com/gvsmirnov/0270f0f15f9498e3b655) ) 後, GC暫停基本上完全消除。有時候 JVM 也很智慧, 會使用 逃逸分析技術(escape analysis technique) 來避免過度分配。簡單來說,JIT編譯器可以通過分析得知, 方法建立的某些物件永遠都不會“逃出”此方法的作用域。這時候就不需要在堆上分配這些物件, 也就不會產生垃圾, 所以JIT編譯器的一種優化手段就是: 消除記憶體分配。請參考 [基準測試](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/jit/EscapeAnalysis.java) **
過早提升
1. 提升速率(promotion rate), 用於衡量單位時間內從年輕代提升到老年代的資料量。一般使用 MB/sec 作為單位, 和分配速率類似
2. JVM會將長時間存活的物件從年輕代提升到老年代。根據分代假設, 可能存在一種情況, 老年代中不僅有存活時間長的物件,也可能有存活時間短的物件。這就是過早提升：物件存活時間還不夠長的時候就被提升到了老年代
3. major GC 不是為頻繁回收而設計的, 但 major GC 現在也要清理這些生命短暫的物件, 就會導致GC暫停時間過長。這會嚴重影響系統的吞吐量
如何測量提升速率
可以指定JVM引數 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps , 通過GC日誌來測量提升速率. JVM記錄的GC暫停資訊如下所示 **
從上面的日誌可以得知： GC之前和之後的 年輕代使用量以及堆記憶體使用量。這樣就可以通過差值算出老年代的使用量。GC日誌中的資訊可以表述為:
根據這些資訊, 就可以計算出觀測週期內的提升速率。平均提升速率為 92 MB/秒, 峰值為 140.95 MB/秒 **
請注意, 只能根據 minor GC 計算提升速率。 Full GC 的日誌不能用於計算提升速率, 因為 major GC 會清理掉老年代中的一部分物件。
提升速率的意義
和分配速率一樣, 提升速率也會影響GC暫停的頻率。但分配速率主要影響 minor GC, 而提升速率則影響 major GC 的頻率。有大量的物件提升,自然很快將老年代填滿。 老年代填充的越快, 則 major GC 事件的頻率就會越高 **
此前說過, full GC 通常需要更多的時間, 因為需要處理更多的物件, 還要執行碎片整理等額外的複雜過程
示例
讓我們看一個[過早提升的示例](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/gc/PrematurePromotion.java)。 這個程式建立/獲取大量的物件/資料,並暫存到集合之中, 達到一定數量後進行批處理:
public class PrematurePromotion {
private static final Collection<byte[]> accumulatedChunks
= new ArrayList<>();
private static void onNewChunk(byte[] bytes) {
accumulatedChunks.add(bytes);
if(accumulatedChunks.size() > MAX_CHUNKS) {
processBatch(accumulatedChunks);
accumulatedChunks.clear();
}
}
}
過早提升的影響
一般來說,過早提升的症狀表現為以下形式:
- - 短時間內頻繁地執行 full GC。
- - 每次 full GC 後老年代的使用率都很低, 在10-20%或以下
- - 提升速率接近於分配速率
要演示這種情況稍微有點麻煩, 所以我們使用特殊手段, 讓物件提升到老年代的年齡比預設情況小很多。指定GC引數 -Xmx24m -XX:NewSize=16m -XX:MaxTenuringThreshold=1, 執行程式之後,可以看到下面的GC日誌:
乍一看似乎不是過早提升的問題。事實上,在每次GC之後老年代的使用率似乎在減少。但反過來想, 要是沒有物件提升或者提升率很小, 也就不會看到這麼多的 Full GC 了。 **
** 簡單解釋一下這裡的GC行為: 有很多物件提升到老年代, 同時老年代中也有很多物件被回收了, 這就造成了老年代使用量減少的假象. 但事實是大量的物件不斷地被提升到老年代, 並觸發 full GC。
解決方案
簡單來說, 要解決這類問題, 需要讓年輕代存放得下暫存的資料。有兩種簡單的方法:
一是增加年輕代的大小, 設定JVM啟動引數, 類似這樣: -Xmx64m -XX:NewSize=32m, 程式在執行時, Full GC 的次數自然會減少很多, 只會對 minor GC的持續時間產生影響:
二是減少每次批處理的數量, 也能得到類似的結果. 至於選用哪個方案, 要根據業務需求決定。在某些情況下, 業務邏輯不允許減少批處理的數量, 那就只能增加堆記憶體,或者重新指定年輕代的大小
** 如果都不可行, 就只能優化資料結構, 減少記憶體消耗。但總體目標依然是一致的: 讓臨時資料能夠在年輕代存放得下 **
6.Weak, Soft 及 Phantom 引用
另一類影響GC的問題是程式中的 non-strong 引用。雖然這類引用在很多情況下可以避免出現 OutOfMemoryError, 但過量使用也會對GC造成嚴重的影響, 反而降低系統性能
弱引用的缺點
首先, 弱引用(weak reference) 是可以被GC強制回收的。當垃圾收集器發現一個弱可達物件(weakly reachable,即指向該物件的引用只剩下弱引用) 時, 就會將其置入相應的ReferenceQueue 中, 變成可終結的物件. 之後可能會遍歷這個 reference queue, 並執行相應的清理。典型的示例是清除快取中不再引用的KEY。
當然, 在這個時候, 我們還可以將該物件賦值給新的強引用, 在最後終結和回收前, GC會再次確認該物件是否可以安全回收。因此, 弱引用物件的回收過程是橫跨多個GC週期的。
實際上弱引用使用的很多。大部分快取框架(caching solution)都是基於弱引用實現的, 所以雖然業務程式碼中沒有直接使用弱引用, 但程式中依然會大量存在
其次, 軟引用(soft reference) 比弱引用更難被垃圾收集器回收. 回收軟引用沒有確切的時間點, 由JVM自己決定. 一般只會在即將耗盡可用記憶體時, 才會回收軟引用,以作最後手段。這意味著, 可能會有更頻繁的 full GC, 暫停時間也比預期更長, 因為老年代中的存活物件會很多。
最後, 使用虛引用(phantom reference)時, 必須手動進行記憶體管理, 以標識這些物件是否可以安全地回收。表面上看起來很正常, 但實際上並不是這樣。 javadoc 中寫道:
In order to ensure that a reclaimable object remains so, the referent of a phantom reference may not be retrieved: The get method of a phantom reference always returns null.
為了防止可回收物件的殘留, 虛引用物件不應該被獲取: phantom reference 的 get 方法返回值永遠是 null。
令人驚訝的是, 很多開發者忽略了下一段內容(這才是重點):
###### Unlike soft and weak references, phantom references are not automatically cleared by the garbage collector as they are enqueued. An object that is reachable via phantom references will remain so until all such references are cleared or themselves become unreachable.
與軟引用和弱引用不同, 虛引用不會被 GC 自動清除, 因為他們被存放到佇列中. 通過虛引用可達的物件會繼續留在記憶體中, 直到呼叫此引用的 clear 方法, 或者引用自身變為不可達。
示例
讓我們看一個[弱引用示例](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/gc/WeakReferences.java), 其中建立了大量的物件, 並在 minor GC 中完成回收。和前面一樣, 修改提升閥值。使用的JVM引數為: **
2.330: [GC (Allocation Failure) 20933K->8229K(22528K), 0.0033848 secs]
2.335: [GC (Allocation Failure) 20517K->7813K(22528K), 0.0022426 secs]
2.339: [GC (Allocation Failure) 20101K->7429K(22528K), 0.0010920 secs]
2.341: [GC (Allocation Failure) 19717K->9157K(22528K), 0.0056285 secs]
2.348: [GC (Allocation Failure) 21445K->8997K(22528K), 0.0041313 secs]
2.354: [GC (Allocation Failure) 21285K->8581K(22528K), 0.0033737 secs]
2.359: [GC (Allocation Failure) 20869K->8197K(22528K), 0.0023407 secs]
2.362: [GC (Allocation Failure) 20485K->7845K(22528K), 0.0011553 secs]
2.365: [GC (Allocation Failure) 20133K->9501K(22528K), 0.0060705 secs]
2.371: [Full GC (Ergonomics) 9501K->2987K(22528K), 0.0171452 secs]可以看到, Full GC 的次數很少。但如果使用弱引用來指向建立的物件, 使用JVM引數 -Dweak.refs=true, 則情況會發生明顯變化. 使用弱引用的原因很多, 比如在 weak hash map 中將物件作為Key的情況。在任何情況下, 使用弱引用都可能會導致以下情形: **
2.059: [Full GC (Ergonomics) 20365K->19611K(22528K), 0.0654090 secs]
2.125: [Full GC (Ergonomics) 20365K->19711K(22528K), 0.0707499 secs]
2.196: [Full GC (Ergonomics) 20365K->19798K(22528K), 0.0717052 secs]
2.268: [Full GC (Ergonomics) 20365K->19873K(22528K), 0.0686290 secs]
2.337: [Full GC (Ergonomics) 20365K->19939K(22528K), 0.0702009 secs]
2.407: [Full GC (Ergonomics) 20365K->19995K(22528K), 0.0694095 secs]可以看到, 發生了多次 full GC, 比起前一節的示例, GC時間增加了一個數量級! 這是過早提升的另一個例子, 但這次情況更加棘手. 當然,問題的根源在於弱引用。這些臨死的物件, 在新增弱引用之後, 被提升到了老年代。 但是, 他們現在陷入另一次GC迴圈之中, 所以需要對其做一些適當的清理。像之前一樣, 最簡單的辦法是增加年輕代的大小, 例如指定JVM引數: -Xmx64m -XX:NewSize=32m: **
2.328: [GC (Allocation Failure) 38940K->13596K(61440K), 0.0012818 secs]
2.332: [GC (Allocation Failure) 38172K->14812K(61440K), 0.0060333 secs]
2.341: [GC (Allocation Failure) 39388K->13948K(61440K), 0.0029427 secs]
2.347: [GC (Allocation Failure) 38524K->15228K(61440K), 0.0101199 secs]
2.361: [GC (Allocation Failure) 39804K->14428K(61440K), 0.0040940 secs]
2.368: [GC (Allocation Failure) 39004K->13532K(61440K), 0.0012451 secs]** 這時候, 物件在 minor GC 中就被回收了 **
更壞的情況是使用軟引用,例如這個[軟引用示例程式](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/gc/SoftReferences.java)。如果程式不是即將發生 OutOfMemoryError , 軟引用物件就不會被回收. 在示例程式中,用軟引用替代弱引用, 立即出現了更多的 Full GC 事件:
2.162: [Full GC (Ergonomics) 31561K->12865K(61440K), 0.0181392 secs]
2.184: [GC (Allocation Failure) 37441K->17585K(61440K), 0.0024479 secs]
2.189: [GC (Allocation Failure) 42161K->27033K(61440K), 0.0061485 secs]
2.195: [Full GC (Ergonomics) 27033K->14385K(61440K), 0.0228773 secs]
2.221: [GC (Allocation Failure) 38961K->20633K(61440K), 0.0030729 secs]
2.227: [GC (Allocation Failure) 45209K->31609K(61440K), 0.0069772 secs]
2.234: [Full GC (Ergonomics) 31609K->15905K(61440K), 0.0257689 secs]最有趣的是虛引用[示例中的虛引用](https://github.com/gvsmirnov/java-perv/blob/master/labs-8/src/main/java/ru/gvsmirnov/perv/labs/gc/PhantomReferences.java), 使用同樣的JVM引數啟動, 其結果和弱引用示例非常相似。實際上, full GC 暫停的次數會小得多, 原因前面說過, 他們有不同的終結方式。
如果禁用虛引用清理, 增加JVM啟動引數 (-Dno.ref.clearing=true), 則可以看到:
4.180: [Full GC (Ergonomics) 57343K->57087K(61440K), 0.0879851 secs]
4.269: [Full GC (Ergonomics) 57089K->57088K(61440K), 0.0973912 secs]
4.366: [Full GC (Ergonomics) 57091K->57089K(61440K), 0.0948099 secs]main 執行緒中丟擲異常 java.lang.OutOfMemoryError: Java heap space
使用虛引用時要小心謹慎, 並及時清理虛可達物件。如果不清理, 很可能會發生 OutOfMemoryError. 請相信我們的經驗教訓: 處理 reference queue 的執行緒中如果沒 catch 住 exception , 系統很快就會被整掛了
使用非強引用的影響
建議使用JVM引數 -XX:+PrintReferenceGC 來看看各種引用對GC的影響. 如果將此引數用於啟動 弱引用示例 , 將會看到:
2.173: [Full GC (Ergonomics)
2.234: [SoftReference, 0 refs, 0.0000151 secs]
2.234: [WeakReference, 2648 refs, 0.0001714 secs]
2.234: [FinalReference, 1 refs, 0.0000037 secs]
2.234: [PhantomReference, 0 refs, 0 refs, 0.0000039 secs]
2.234: [JNI Weak Reference, 0.0000027 secs]
[PSYoungGen: 9216K->8676K(10752K)]
[ParOldGen: 12115K->12115K(12288K)]
21331K->20792K(23040K),
[Metaspace: 3725K->3725K(1056768K)],
0.0766685 secs]
[Times: user=0.49 sys=0.01, real=0.08 secs]
2.250: [Full GC (Ergonomics)
2.307: [SoftReference, 0 refs, 0.0000173 secs]
2.307: [WeakReference, 2298 refs, 0.0001535 secs]
2.307: [FinalReference, 3 refs, 0.0000043 secs]
2.307: [PhantomReference, 0 refs, 0 refs, 0.0000042 secs]
2.307: [JNI Weak Reference, 0.0000029 secs]
[PSYoungGen: 9215K->8747K(10752K)]
[ParOldGen: 12115K->12115K(12288K)]
21331K->20863K(23040K),
[Metaspace: 3725K->3725K(1056768K)],
0.0734832 secs]
[Times: user=0.52 sys=0.01, real=0.07 secs]
2.323: [Full GC (Ergonomics)
2.383: [SoftReference, 0 refs, 0.0000161 secs]
2.383: [WeakReference, 1981 refs, 0.0001292 secs]
2.383: [FinalReference, 16 refs, 0.0000049 secs]
2.383: [PhantomReference, 0 refs, 0 refs, 0.0000040 secs]
2.383: [JNI Weak Reference, 0.0000027 secs]
[PSYoungGen: 9216K->8809K(10752K)]
[ParOldGen: 12115K->12115K(12288K)]
21331K->20925K(23040K),
[Metaspace: 3725K->3725K(1056768K)],
0.0738414 secs]
[Times: user=0.52 sys=0.01, real=0.08 secs]只有確定 GC 對應用的吞吐量和延遲造成影響之後, 才應該花心思來分析這些資訊, 審查這部分日誌。通常情況下, 每次GC清理的引用數量都是很少的, 大部分情況下為 0。如果GC 花了較多時間來清理這類引用, 或者清除了很多的此類引用, 就需要進一步觀察和分析了
解決方案
如果程式確實碰到了 mis-, ab- 問題或者濫用 weak, soft, phantom 引用, 一般都要修改程式的實現邏輯。每個系統不一樣, 因此很難提供通用的指導建議, 但有一些常用的辦法: **
- - 弱引用(Weak references) —— 如果某個記憶體池的使用量增大, 造成了效能問題, 那麼增加這個記憶體池的大小(可能也要增加堆記憶體的最大容量)。如同示例中所看到的, 增加堆記憶體的大小, 以及年輕代的大小, 可以減輕症狀。
- - 虛引用(Phantom references) —— 請確保在程式中呼叫了虛引用的 clear 方法。程式設計中很容易忽略某些虛引用, 或者清理的速度跟不上生產的速度, 又或者清除引用佇列的執行緒掛了, 就會對GC 造成很大壓力, 最終可能引起 OutOfMemoryError。
- - 軟引用(Soft references) —— 如果確定問題的根源是軟引用, 唯一的解決辦法是修改程式原始碼, 改變內部實現邏輯。
其他示例
前面介紹了最常見的GC效能問題。但我們學到的很多原理都沒有具體的場景來展現。本節介紹一些不常發生, 但也可能會碰到的問題。
RMI 與 GC
如果系統提供或者消費 RMI 服務, 則JVM會定期執行 full GC 來確保本地未使用的物件在另一端也不佔用空間. 記住, 即使你的程式碼中沒有釋出 RMI 服務, 但第三方或者工具庫也可能會開啟 RMI 終端. 最常見的元凶是 JMX, 如果通過JMX連線到遠端, 底層則會使用 RMI 釋出資料
問題是有很多不必要的週期性 full GC。檢視老年代的使用情況, 一般是沒有記憶體壓力, 其中還存在大量的空閒區域, 但 full GC 就是被觸發了, 也就會暫停所有的應用執行緒 **
這種週期性呼叫 System.gc() 刪除遠端引用的行為, 是在 sun.rmi.transport.ObjectTable 類中, 通過 sun.misc.GC.requestLatency(long gcInterval) 呼叫的
對許多應用來說, 根本沒必要, 甚至對效能有害。 禁止這種週期性的 GC 行為, 可以使用以下 JVM 引數:
java -Dsun.rmi.dgc.server.gcInterval=9223372036854775807L
-Dsun.rmi.dgc.client.gcInterval=9223372036854775807L
com.yourcompany.YourApplication** 這讓 Long.MAX_VALUE 毫秒之後, 才呼叫 System.gc(), 實際執行的系統可能永遠都不會觸發。 **
ObjectTable.class
巨無霸物件的分配
如果使用 G1 垃圾收集演算法, 會產生一種巨無霸物件引起的 GC 效能問題
** 說明: 在G1中, 巨無霸物件是指所佔空間超過一個小堆區(region) 50% 的物件 **
頻繁的建立巨無霸物件, 無疑會造成GC的效能問題, 看看G1的處理方式:
- 如果某個 region 中含有巨無霸物件, 則巨無霸物件後面的空間將不會被分配。如果所有巨無霸物件都超過某個比例, 則未使用的空間就會引發記憶體碎片問題。
- G1 沒有對巨無霸物件進行優化。這在 JDK 8 以前是個特別棘手的問題 —— 在 Java 1.8u40 之前的版本中, 巨無霸物件所在 region 的回收只能在 full GC 中進行。最新版本的 Hotspot JVM, 在 marking 階段之後的 cleanup 階段中釋放巨無霸區間, 所以這個問題在新版本JVM中的影響已大大降低。
要監控是否存在巨無霸物件, 可以開啟GC日誌, 使用的命令如下:
java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+PrintReferenceGC -XX:+UseG1GC
-XX:+PrintAdaptiveSizePolicy -Xmx128m
MyClass這樣的日誌就是證據, 表明程式中確實建立了巨無霸物件. 可以看到: G1 Humongous Allocation 是 GC暫停的原因。 再看前面一點的 allocation request: 1048592 bytes , 可以發現程式試圖分配一個 1,048,592 位元組的物件, 這要比巨無霸區域(2MB)的 50% 多出 16 個位元組。
第一種解決方式, 是修改 region size , 以使得大多數的物件不超過 50%, 也就不進行巨無霸物件區域的分配。 region 的預設大小在啟動時根據堆記憶體的大小算出。但也可以指定引數來覆蓋預設設定, -XX:G1HeapRegionSize=XX。 指定的 region size 必須在 1~32MB 之間, 還必須是2的冪 【2^10 = 1024 = 1KB; 2^20=1MB; 所以 region size 只能是: 1m,2m,4m,8m,16m,32m】。
這種方式也有副作用, 增加 region 的大小也就變相地減少了 region 的數量, 所以需要謹慎使用, 最好進行一些測試, 看看是否改善了吞吐量和延遲。
更好的方式需要一些工作量, 如果可以的話, 在程式中限制物件的大小。最好是使用分析器, 展示出巨無霸物件的資訊, 以及分配時所在的堆疊跟蹤資訊。
總結
JVM上執行的程式多種多樣, 啟動引數也有上百個, 其中有很多會影響到 GC, 所以調優GC效能的方法也有很多種。
還是那句話, 沒有真正的銀彈, 能滿足所有的效能調優指標。 我們能做的只是介紹一些常見的/和不常見的示例, 讓你在碰到類似問題時知道是怎麼回事。深入理解GC的工作原理, 熟練應用各種工具, 就可以進行GC調優, 提高程式效能。