JVM虛擬機器器調優實戰(3)進階調優篇

2020-10-14 11:00:32

1.JVM記憶體分配與回收

1.1Minor Gc和Full GC 有什麼不同呢?

   新生代GC(Minor GC):指發生新生代的的垃圾收集動作,Minor GC非常頻繁,回收速度一般也比較快。

   老年代GC(Major GC/Full GC):指發生在老年代的GC,出現了Major GC經常會伴隨至少一次的Minor GC(並非絕對),Major GC的速度一般會比Minor GC的慢10倍以上。

1.2物件優先在Eden區進行分配

解釋:大多數情況下,物件在新生代中 Eden 區分配。當 Eden 區沒有足夠空間進行分配時,虛擬機器器將發起一次Minor GC。

測試範例:

程式碼



public class GCTest {
	public static void main(String[] args) throws InterruptedException {
		byte[] allocation1/*, allocation2, allocation3, allocation4, allocation5, allocation6*/;
		allocation1 = new byte[30231 * 1024];
		/*allocation2 = new byte[900*1024];
		allocation3 = new byte[1000*1024];
        allocation4 = new byte[1000*1024];
        allocation5 = new byte[1000*1024];
        allocation6 = new byte[1000*1024];*/
        //Thread.sleep(Integer.MAX_VALUE);
	}
}


idea啟動虛擬機器器新增引數:
在這裡插入圖片描述
新增的引數: -XX:+PrintGCDetails

結果:
在這裡插入圖片描述
從上圖我們可以看出eden區記憶體幾乎已經被分配完全(即使程式什麼也不做,新生代也會使用至少2000多k記憶體)。


假如我們再為allocation2,3,4,5分配記憶體會出現什麼情況呢?
![在這裡插入圖片描述](https://img-blog.csdnimg.cn/2020100821171710.png#pic_center
因為給allocation2,3,4,5分配記憶體的時候eden區記憶體幾乎已經被分配完了,我們剛剛講了當Eden區沒有足夠空間進行分配時,虛擬機器器將發起一次Minor GC.GC期間虛擬機器器又發現allocation1無法存入Survior空間,所以只好通過 分配擔保機制 把新生代的物件提前轉移到老年代中去,老年代上的空間足夠存放allocation1,所以不會出現Full GC。執行Minor GC後,後面分配的物件如果能夠存在eden區的話,還是會在eden區分配記憶體

1.3 大物件直接進入老年代

測試程式碼:


public class GCTest {
	public static void main(String[] args) throws InterruptedException {
		byte[] allocation1;
		allocation1 = new byte[90231 * 1024];

	}
}

結果:
在這裡插入圖片描述

大物件就是需要大量連續記憶體空間的物件(比如:字串、陣列)。從上邊的測試範例來看,這個allocation1超大物件並沒有進新生代,而是直接進入了老年代。

1.4長期存活的物件將進入老年代

既然虛擬機器器採用了分代收集的思想來管理記憶體,那麼記憶體回收時就必須能識別那些物件應放在新生代,那些物件應放在老年代中。為了做到這一點,虛擬機器器給每個物件一個物件年齡(Age)計數器。
如果物件在 Eden 出生並經過第一次 Minor GC 後仍然能夠存活,並且能被 Survivor 容納的話,將被移動到 Survivor 空間中,並將物件年齡設為1.物件在 Survivor 中每熬過一次 MinorGC,年齡就增加1歲,當它的年齡增加到一定程度(預設為15歲),就會被晉升到老年代中。物件晉升到老年代的年齡閾值,可以通過引數 -XX:MaxTenuringThreshold 來設定。一般不建議修改。

2.如何判斷物件可以被回收

堆中幾乎放著所有的物件範例,對堆垃圾回收前的第一步就是要判斷那些物件已經死亡(即不能再被任何途徑使用的物件)。

2.1參照計數法

給物件中新增一個參照計數器,每當有一個地方參照它,計數器就加1;當參照失效,計數器就減1;任何時候計數器為0的物件就是不可能再被使用的。
這個方法實現簡單,效率高,但是目前主流的虛擬機器器中並沒有選擇這個演演算法來管理記憶體,其最主要的原因是它很難解決物件之間相互迴圈參照的問題。 所謂物件之間的相互參照問題,如下面程式碼所示:除了物件objA 和 objB 相互參照著對方之外,這兩個物件之間再無任何參照。但是他們因為互相參照對方,導致它們的參照計數器都不為0,於是參照計數演演算法無法通知 GC 回收器回收他們。

範例程式碼


public class ReferenceCountingGc {
	Object instance = null;

	public static void main(String[] args) {
		ReferenceCountingGc A = new ReferenceCountingGc();
		ReferenceCountingGc B = new ReferenceCountingGc();
		A.instance = B;
		B.instance = A;
		A = null;
		B = null;
	}
}

圖例解釋:
在這裡插入圖片描述
兩物件互相參照對方,但是有無其他參照,所以這個物件為廢物件,但是參照值都是1,所以無法GC;

2.2可達性分析演演算法

解釋:這個演演算法的基本思想就是通過一系列的稱為 「GC Roots」 的物件作為起點,從這些節點開始向下搜尋,節點所走過的路徑稱為參照鏈,當一個物件到 GC Roots 沒有任何參照鏈相連的話,則證明此物件是不可用的。
GC Roots根節點:類載入器、Thread、虛擬機器器棧的本地變數表、static成員、常數參照、本地方法棧的變數等等

在這裡插入圖片描述

2.3 如何判斷一個常數是廢棄常數?

執行時常數池主要回收的是廢棄的常數。那麼,我們如何判斷一個常數是廢棄常數呢?
假如在常數池中存在字串 「abc」,如果當前沒有任何String物件參照該字串常數的話,就說明常數 「abc」 就是廢棄常數,如果這時發生記憶體回收的話而且有必要的話,「abc」 就會被系統清理出常數池。

2.4 如何判斷一個類是無用的類?

方法區主要回收的是無用的類,那麼如何判斷一個類是無用的類的呢?
判定一個常數是否是「廢棄常數」比較簡單,而要判定一個類是否是「無用的類」的條件則相對苛刻許多。類需要同時滿足下面3個條件才能算是 「無用的類」 :
    該類所有的範例都已經被回收,也就是 Java 堆中不存在該類的任何範例。
    載入該類的 ClassLoader 已經被回收。
    該類對應的 java.lang.Class 物件沒有在任何地方被參照,無法在任何地方通過反射存取該類的方法。
虛擬機器器可以對滿足上述3個條件的無用類進行回收,這裡說的僅僅是「可以」,而並不是和物件一樣不使用了就會必然被回收。

3.finalize()方法最終判定物件是否存活

即使在可達性分析演演算法中不可達的物件,也並非是「非死不可」的,這時候它們暫時處於「緩刑」階段,要真正宣告一個物件死亡,至少要經歷再次標記過程。標記的前提是物件在進行可達性分析後發現沒有與GC Roots相連線的參照鏈。

  1. 第一次標記並進行一次篩選。
    篩選的條件是此物件是否有必要執行finalize()方法。當物件沒有覆蓋finalize方法,或者finzlize方法已經被虛擬機器器呼叫過,虛擬機器器將這兩種情況都視為「沒有必要執行」,物件被回收。
  2. 第二次標記
    如果這個物件被判定為有必要執行finalize()方法,那麼這個物件將會被放置在一個名為:F-Queue的佇列之中,並在稍後由一條虛擬機器器自動建立的、低優先順序的Finalizer執行緒去執行。這裡所謂的「執行」是指虛擬機器器會觸發這個方法,但並不承諾會等待它執行結束。這樣做的原因是,如果一個物件finalize()方法中執行緩慢,或者發生死迴圈(更極端的情況),將很可能會導致F-Queue佇列中的其他物件永久處於等待狀態,甚至導致整個記憶體回收系統崩潰。
    finalize()方法是物件脫逃死亡命運的最後一次機會,稍後GC將對F-Queue中的物件進行第二次小規模標記,如果物件要在finalize()中成功拯救自己----只要重新與參照鏈上的任何的一個物件建立關聯即可,譬如把自己賦值給某個類變數或物件的成員變數,那在第二次標記時它將移除出「即將回收」的集合。如果物件這時候還沒逃脫,那基本上它就真的被回收了。

4.垃圾收集演演算法

4.1 主要演演算法

標記-清除,複製演演算法,標記-整理,分帶收集

4.2 標記-清除演演算法

解釋:GCRoot完畢以後,對垃圾物件進行標記,標記完清除垃圾物件
弊端:產生垃圾碎片,清理記憶體時要遍歷整個記憶體格,浪費算力
圖例:
在這裡插入圖片描述

4.2 複製演演算法
解釋:將記憶體分成A和B兩塊記憶體區域,B塊不使用,物件會首先存到在A區,再將A塊記憶體垃圾物件進行回收,等回收完畢後,將A塊存活物件並連續放到B快上。
優勢:不會產生垃圾碎片=>適用於年輕代的survival的From和To區
圖例:
在這裡插入圖片描述
4.3標記-整理演演算法
解釋:根據老年代的特點特出的一種標記演演算法,標記過程仍然與「標記-清除」演演算法一樣,但後續步驟不是直接對可回收物件回收,而是讓所有存活的物件向一段移動,然後直接清理掉端邊界以外的記憶體。
圖例:
在這裡插入圖片描述
4.4 分代收集演演算法

解釋:當前虛擬機器器的垃圾收集都採用分代收集演演算法,這種演演算法沒有什麼新的思想,只是根據物件存活週期的不同將記憶體分為幾塊。一般將java堆分為新生代和老年代,這樣我們就可以根據各個年代的特點選擇合適的垃圾收集演演算法。

舉例:在新生代中,每次收集都會有大量物件死去,所以可以選擇複製演演算法,只需要付出少量物件的複製成本就可以完成每次垃圾收集。而老年代的物件存活機率是比較高的,而且沒有額外的空間對它進行分配擔保,所以我們必須選擇「標記-清除」或「標記-整理」演演算法進行垃圾收集。

4.垃圾收集器

前置知識:
(1)垃圾收集器是垃圾收集演演算法的具體實現,不同場景選用不同的垃圾回收器
(2)並行:多條垃圾回收執行緒並行工作     並行:應用執行緒(使用者執行緒)與垃圾收集器執行緒同時執行(收集過程不一定是並行,有可能是交替執行)
(3)雖然我們對各個收集器進行比較,但並非為了挑選出一個最好的收集器。因為直到現在為止還沒有最好的垃圾收集器出現,更加沒有萬能的垃圾收集器,我們能做的就是根據具體應用場景選擇適合自己的垃圾收集器。試想一下:如果有一種四海之內、任何場景下都適用的完美收集器存在,那麼我們的HotSpot虛擬機器器就不會實現那麼多不同的垃圾收集器了。

4.1 Serial收集器

Serial(序列)收集器收集器是最基本、歷史最悠久的垃圾收集器了。大家看名字就知道這個收集器是一個單執行緒收集器了。它的 「單執行緒」 的意義不僅僅意味著它只會使用一條垃圾收集執行緒去完成垃圾收集工作,更重要的是它在進行垃圾收集工作的時候必須暫停其他所有的工作執行緒( 「Stop The World」 ),直到它收集結束。

新生代採用複製演演算法,老年代採用標記-整理演演算法。
在這裡插入圖片描述

虛擬機器器的設計者們當然知道Stop The World帶來的不良使用者體驗,所以在後續的垃圾收集器設計中停頓時間在不斷縮短(仍然還有停頓,尋找最優秀的垃圾收集器的過程仍然在繼續)。
但是Serial收集器有沒有優於其他垃圾收集器的地方呢?當然有,它簡單而高效(與其他收集器的單執行緒相比)。Serial收集器由於沒有執行緒互動的開銷,自然可以獲得很高的單執行緒收集效率。

4.2 ParNew收集器

ParNew收集器其實就是Serial收集器的多執行緒版本,除了使用多執行緒進行垃圾收集外,其餘行為(控制引數、收集演演算法、回收策略等等)和Serial收集器完全一樣。

新生代採用複製演演算法,老年代採用標記-整理演演算法。
在這裡插入圖片描述
它是許多執行在Server模式下的虛擬機器器的首要選擇,除了Serial收集器外,只有它能與CMS收集器(真正意義上的並行收集器,後面會介紹到)配合工作。

4.3 Parallel Scavenge收集器(jdk8預設垃圾收集器

Parallel Scavenge 收集器類似於ParNew 收集器,是Server 模式(記憶體大於2G,2個cpu)下的預設收集器,那麼它有什麼特別之處呢?

Parallel Scavenge收集器關注點是吞吐量(高效率的利用CPU)。CMS等垃圾收集器的關注點更多的是使用者執行緒的停頓時間(提高使用者體驗)。所謂吞吐量就是CPU中用於執行使用者程式碼的時間與CPU總消耗時間的比值。 Parallel Scavenge收集器提供了很多引數供使用者找到最合適的停頓時間或最大吞吐量,如果對於收集器運作不太瞭解的話,可以選擇把記憶體管理優化交給虛擬機器器去完成也是一個不錯的選擇。
新生代採用複製演演算法,老年代採用標記-整理演演算法。
在這裡插入圖片描述
4.4 Serial Old收集器

Serial收集器的老年代版本,它同樣是一個單執行緒收集器。它主要有兩大用途:一種用途是在JDK1.5以及以前的版本中與Parallel Scavenge收集器搭配使用,另一種用途是作為CMS收集器的後備方案。

4.5 Parallel Old收集器

Parallel Scavenge收集器的老年代版本。使用多執行緒和「標記-整理」演演算法。在注重吞吐量以及CPU資源的場合,都可以優先考慮 Parallel Scavenge收集器和Parallel Old收集器。

4.6 CMS收集器(-XX:+UseConcMarkSweepGC(主要是old區使用))

CMS(Concurrent Mark Sweep)收集器是一種以獲取最短回收停頓時間為目標的收集器。它而非常符合在注重使用者體驗的應用上使用,它是HotSpot虛擬機器器第一款真正意義上的並行收集器,它第一次實現了讓垃圾收集執行緒與使用者執行緒(基本上)同時工作。
從名字中的Mark Sweep這兩個詞可以看出,CMS收集器是一種 「標記-清除」演演算法實現的,它的運作過程相比於前面幾種垃圾收集器來說更加複雜一些。整個過程分為四個步驟:
初始標記: 暫停所有的其他執行緒(STW),並記錄下直接與GCRoot相連的物件,速度很快 ;
並行標記: 同時開啟GC和使用者執行緒,用一個閉包結構去記錄可達物件。但在這個階段結束,這個閉包結構並不能保證包含當前所有的可達物件。因為使用者執行緒可能會不斷的更新參照域,所以GC執行緒無法保證可達性分析的實時性。所以這個演演算法裡會跟蹤記錄這些發生參照更新的地方。
重新標記: 重新標記階段就是為了修正並行標記期間因為使用者程式繼續執行而導致標記產生變動的那一部分物件的標記記錄,這個階段的停頓時間一般會比初始標記階段的時間稍長,遠遠比並行標記階段時間短(重新標記的意義就是在再並行標記過程當中,因為垃圾回收執行緒與使用者執行緒或者是說程式執行緒是並行的,所以在這個過程當中又會產生垃圾物件,所以要重新標記)
並行清除: 開啟使用者執行緒,同時GC執行緒開始對未標記的區域做清掃。
在這裡插入圖片描述

從它的名字就可以看出它是一款優秀的垃圾收集器,主要優點:並行收集、低停頓。但是它有下面三個明顯的缺點:
對CPU資源敏感(會和服務搶資源);
無法處理浮動垃圾(在java業務程式執行緒與垃圾收集執行緒並行執行過程中又產生的垃圾,這種浮動垃圾只能等到下一次gc再清理了);
它使用的回收演演算法-「標記-清除」演演算法會導致收集結束時會有大量空間碎片產生。
CMS的相關引數
-XX:+UseConcMarkSweepGC 啟用cms
-XX:ConcGCThreads:並行的GC執行緒數(並非STW時間,而是和服務一起執行的執行緒數)
-XX:+UseCMSCompactAtFullCollection:FullGC之後做壓縮(減少碎片)
-XX:CMSFullGCsBeforeCompaction:多少次FullGC之後壓縮一次(因壓縮非常的消耗時間,所以不能每次FullGC都做)
-XX:CMSInitiatingOccupancyFraction:觸發FulGC條件(預設是92)
-XX:+UseCMSInitiatingOccupancyOnly:是否動態調節
-XX:+CMSScavengeBeforeRemark:FullGC之前先做YGC(一般這個引數是開啟的)
-XX:+CMSClassUnloadingEnabled:啟用回收Perm區(jdk1.7及以前)

4.7 G1收集器(-XX:+UseG1GC)

G1 (Garbage-First)是一款面向伺服器的垃圾收集器,主要針對配備多顆處理器及大容量記憶體的機器. 以極高概率滿足GC停頓時間要求的同時,還具備高吞吐量效能特徵.

在這裡插入圖片描述
在這裡插入圖片描述

特點:
(1)並行與並行:G1能充分利用CPU、多核環境下的硬體優勢,使用多個CPU(CPU或者CPU核心)來縮短Stop-The-World停頓時間。部分其他收集器原本需要停頓Java執行緒來執行GC動作,G1收集器仍然可以通過並行的方式讓java程式繼續執行。
(2)分代收集:雖然G1可以不需要其他收集器配合就能獨立管理整個GC堆,但是還是保留了分代的概念。
(3)空間整合:與CMS的「標記–清理」演演算法不同,G1從整體來看是基於「標記整理」演演算法實現的收集器;從區域性上來看是基於「複製」演演算法實現的。
(4)可預測的停頓:這是G1相對於CMS的另一個大優勢,降低停頓時間是G1 和 CMS 共同的關注點,但G1 除了追求低停頓外,還能建立可預測的停頓時間模型,能讓使用者明確指定在一個長度為M毫秒的時間片段內完成垃圾收集。

GC步驟:
初始標記(initial mark,STW):在此階段,G1 GC 對根進行標記。該階段與常規的 (STW) 年輕代垃圾回收密切相關。
並行標記(Concurrent Marking):G1 GC 在整個堆中查詢可存取的(存活的)物件。
最終標記(Remark,STW):該階段是 STW 回收,幫助完成標記週期。
篩選回收(Cleanup,STW):篩選回收階段首先對各個Region的回收價值和成本進行排序,根據使用者所期望的GC停頓時間來制定回收計劃,這個階段其實也可以做到與使用者程式一起並行執行,但是因為只回收一部分Region,時間是使用者可控制的,而且停頓使用者執行緒將大幅提高收集效率。
在這裡插入圖片描述
G1收集器在後臺維護了一個優先列表,每次根據允許的收集時間,優先選擇回收價值最大的Region(這也就是它的名字Garbage-First的由來)。這種使用Region劃分記憶體空間以及有優先順序的區域回收方式,保證了GF收集器在有限時間內可以儘可能高的收集效率。

G1垃圾收集分類:
YoungGC
新物件進入Eden區
存活物件拷貝到Survivor區
存活時間達到年齡閾值時,物件晉升到Old區
MixedGC
不是FullGC,回收所有的Young和部分Old(根據期望的GC停頓時間確定old區垃圾收集的優先順序)
global concurrent marking (全域性並行標記)
Initial marking phase:標記GC Root,STW
Root region scanning phase:標記存活Region
Concurrent marking phase:標記存活的物件
Remark phase :重新標記,STW
Cleanup phase:部分STW
相關引數
G1MixedGCLiveThresholdPercent Old區的region被回收的時候的存活物件佔比
G1MixedGCCountTarget:一次global concurrent marking之後,最多執行Mixed GC的次數
G1OldCSetRegionThresholdPercent 一次Mixed GC中能被選入CSet的最多old區的region數量
觸發的時機
InitiatingHeapOccupancyPercent:堆佔有率達到這個值則觸發global concurrent marking,預設45%
G1HeapWastePercent:在global concurrent marking結束之後,可以知道區有多少空間要被回收,在每次YGC之後和再次發生Mixed GC之前,會檢查垃圾佔比是否達到了此引數,只有達到了,下次才會發生Mixed GC

5. 如何選擇垃圾收集器

優先調整堆的大小讓伺服器自己來選擇
如果記憶體小於100M,使用序列收集器
如果是單核,並且沒有停頓時間的要求,序列或JVM自己選擇
如果允許停頓時間超過1秒,選擇並行或者JVM自己選
如果響應時間最重要,並且不能超過1秒,使用並行收集器
下圖有連線的可以搭配使用,官方推薦使用G1,因為效能高
在這裡插入圖片描述

6. 虛擬機器器實戰調優

6.1 主要調優方向

停頓時間: 垃圾收集器做垃圾回收中斷應用執行的時間。 -XX:MaxGCPauseMillis
吞吐量:垃圾收集的時間和總時間的佔比:1/(1+n),吞吐量為1-1/(1+n) 。
-XX:GCTimeRatio=n

6.2 GC調優步驟

第一步:列印GC紀錄檔 在啟動Java類上或者jar包上新增-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc.log
第二步:分析紀錄檔得到關鍵性指標(這裡可以直接點開生成檔案進行分析,或者直接使用gcessy進行分析https://www.gceasy.io/
第三步:分析不同的GC原因,調優JVM引數

6.3分析不同垃圾收集器的log紀錄檔

6.3.1 Parallel Scavenge收集器(jdk8預設垃圾收集器)

使用命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc-Parallel.log -jar jar包包名

生成檔案:

Java HotSpot(TM) 64-Bit Server VM (25.261-b12) for windows-amd64 JRE (1.8.0_261-b12), built on Jun 18 2020 06:56:32 by "" with unknown MS VC++:1916
Memory: 4k page, physical 12421516k(8723388k free), swap 14911884k(10572880k free)
CommandLine flags: -XX:InitialHeapSize=198744256 -XX:MaxHeapSize=3179908096 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers 
-XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2020-10-13T20:24:36.336+0800: 0.790: [GC (Allocation Failure) [PSYoungGen: 49152K->3781K(56832K)] 49152K->3789K(186880K), 0.0037607 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:37.447+0800: 1.901: [GC (Allocation Failure) [PSYoungGen: 52933K->3267K(56832K)] 52941K->3283K(186880K), 0.0092661 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:37.673+0800: 2.127: [GC (Allocation Failure) [PSYoungGen: 52419K->3932K(56832K)] 52435K->3956K(186880K), 0.0043522 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:37.799+0800: 2.253: [GC (Allocation Failure) [PSYoungGen: 53084K->4465K(105984K)] 53108K->4497K(236032K), 0.0045214 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-13T20:24:38.060+0800: 2.514: [GC (Allocation Failure) [PSYoungGen: 102769K->6127K(105984K)] 102801K->6167K(236032K), 0.0073281 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.448+0800: 2.901: [GC (Allocation Failure) [PSYoungGen: 104431K->6115K(201728K)] 104471K->6479K(331776K), 0.0087878 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.810+0800: 3.264: [GC (Metadata GC Threshold) [PSYoungGen: 115257K->5100K(202752K)] 115621K->7866K(332800K), 0.0093521 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:38.820+0800: 3.274: [Full GC (Metadata GC Threshold) [PSYoungGen: 5100K->0K(202752K)] [ParOldGen: 2766K->7381K(77312K)] 7866K->7381K(280064K), 
[Metaspace: 20835K->20835K(1069056K)], 0.0398476 secs] [Times: user=0.08 sys=0.00, real=0.04 secs] 
2020-10-13T20:24:40.396+0800: 4.850: [GC (Allocation Failure) [PSYoungGen: 195584K->3879K(310784K)] 202965K->11269K(388096K), 0.0044406 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-13T20:24:41.644+0800: 6.098: [GC (Allocation Failure) [PSYoungGen: 310567K->7167K(395264K)] 317957K->16293K(472576K), 0.0184908 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] 
2020-10-13T20:24:44.059+0800: 8.514: [GC (Allocation Failure) [PSYoungGen: 395263K->8680K(415232K)] 404389K->24965K(492544K), 0.0216513 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2020-10-13T20:24:45.681+0800: 10.134: [GC (Metadata GC Threshold) [PSYoungGen: 385705K->6605K(418816K)] 401990K->31483K(496128K), 0.0258426 secs] [Times: user=0.05 sys=0.01, real=0.03 secs] 
2020-10-13T20:24:45.706+0800: 10.160: [Full GC (Metadata GC Threshold) [PSYoungGen: 6605K->0K(418816K)] [ParOldGen: 24877K->24437K(134656K)] 31483K->24437K(553472K), 
[Metaspace: 34873K->34873K(1081344K)], 0.1252288 secs] [Times: user=0.39 sys=0.02, real=0.13 secs] 
2020-10-13T20:24:47.241+0800: 11.695: [GC (Allocation Failure) [PSYoungGen: 406528K->5168K(530944K)] 430965K->29613K(665600K), 0.0218360 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
2020-10-13T20:24:51.189+0800: 15.642: [GC (Allocation Failure) [PSYoungGen: 530480K->6580K(545280K)] 554925K->34797K(679936K), 0.0271547 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
2020-10-13T20:24:54.730+0800: 19.184: [GC (Allocation Failure) [PSYoungGen: 540596K->11240K(676352K)] 568813K->43242K(811008K), 0.0191988 secs] [Times: user=0.05 sys=0.02, real=0.02 secs] 
Heap
 PSYoungGen      total 676352K, used 260893K [0x0000000780d00000, 0x00000007ab300000, 0x00000007c0000000)
  eden space 665088K, 37% used [0x0000000780d00000,0x00000007900cd530,0x00000007a9680000)
  from space 11264K, 99% used [0x00000007aa400000,0x00000007aaefa050,0x00000007aaf00000)
  to   space 13824K, 0% used [0x00000007a9680000,0x00000007a9680000,0x00000007aa400000)
 ParOldGen       total 134656K, used 32002K [0x0000000702600000, 0x000000070a980000, 0x0000000780d00000)
  object space 134656K, 23% used [0x0000000702600000,0x0000000704540aa0,0x000000070a980000)
 Metaspace       used 47342K, capacity 48044K, committed 48128K, reserved 1091584K
  class space    used 6126K, capacity 6317K, committed 6400K, reserved 1048576K

生成檔案分析:

在這裡插入圖片描述

easyGC分析:此處發現easyGC給出了一個方案進行優化,55%的時間使用原空間的gc上。
在這裡插入圖片描述
解決方案:

第一次調優,設定Metaspace大小:增大元空間大小-XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M

第二次調優,增大年輕代動態擴容增量,預設是20(%),可以減少young gc:-XX:YoungGenerationSizeIncrement=30

6.3.2 CMS收集器

使用命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -Xloggc:./gc-cms.log -jar jar包包名

生成檔案:

Java HotSpot(TM) 64-Bit Server VM (25.261-b12) for windows-amd64 JRE (1.8.0_261-b12), built on Jun 18 2020 06:56:32 by "" with unknown MS VC++:1916
Memory: 4k page, physical 12421516k(7900700k free), swap 14911884k(9400336k free)
CommandLine flags: -XX:InitialHeapSize=198744256 -XX:MaxHeapSize=3179908096 -XX:MaxNewSize=348966912 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
2020-10-12T20:27:56.377+0800: 1.821: [GC (Allocation Failure) 2020-10-12T20:27:56.377+0800: 1.821: [ParNew: 51904K->3711K(58368K), 0.0057649 secs] 51904K->3711K(188096K), 0.0059787 secs] [Times: user=0.02 sys=0.03, real=0.01 secs] 
2020-10-12T20:27:57.783+0800: 3.227: [GC (Allocation Failure) 2020-10-12T20:27:57.783+0800: 3.227: [ParNew: 55615K->2476K(58368K), 0.0126847 secs] 55615K->4727K(188096K), 0.0127688 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:58.167+0800: 3.611: [GC (Allocation Failure) 2020-10-12T20:27:58.167+0800: 3.611: [ParNew: 54380K->2729K(58368K), 0.0022000 secs] 56631K->4980K(188096K), 0.0022973 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.313+0800: 3.757: [GC (Allocation Failure) 2020-10-12T20:27:58.313+0800: 3.757: [ParNew: 54633K->2827K(58368K), 0.0026017 secs] 56884K->5077K(188096K), 0.0026982 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.429+0800: 3.873: [GC (Allocation Failure) 2020-10-12T20:27:58.429+0800: 3.873: [ParNew: 54731K->2856K(58368K), 0.0029748 secs] 56981K->5107K(188096K), 0.0030499 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:58.691+0800: 4.134: [GC (Allocation Failure) 2020-10-12T20:27:58.691+0800: 4.134: [ParNew: 54760K->3336K(58368K), 0.0052064 secs] 57011K->5587K(188096K), 0.0052964 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:58.849+0800: 4.293: [GC (Allocation Failure) 2020-10-12T20:27:58.849+0800: 4.293: [ParNew: 55240K->3398K(58368K), 0.0043610 secs] 57491K->5649K(188096K), 0.0044512 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.145+0800: 4.589: [GC (Allocation Failure) 2020-10-12T20:27:59.145+0800: 4.589: [ParNew: 55302K->4295K(58368K), 0.0044396 secs] 57553K->6801K(188096K), 0.0045450 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.525+0800: 4.969: [GC (Allocation Failure) 2020-10-12T20:27:59.525+0800: 4.969: [ParNew: 56199K->5380K(58368K), 0.0057412 secs] 58705K->8376K(188096K), 0.0058236 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.812+0800: 5.256: [GC (Allocation Failure) 2020-10-12T20:27:59.812+0800: 5.256: [ParNew: 57284K->4631K(58368K), 0.0074203 secs] 60280K->8742K(188096K), 0.0075285 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:27:59.820+0800: 5.264: [GC (CMS Initial Mark) [1 CMS-initial-mark: 4111K(129728K)] 8742K(188096K), 0.0013292 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:59.821+0800: 5.265: [CMS-concurrent-mark-start]
2020-10-12T20:27:59.865+0800: 5.308: [CMS-concurrent-mark: 0.043/0.043 secs] [Times: user=0.19 sys=0.00, real=0.04 secs] 
2020-10-12T20:27:59.865+0800: 5.308: [CMS-concurrent-preclean-start]
2020-10-12T20:27:59.866+0800: 5.310: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:27:59.866+0800: 5.310: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:01.145+0800: 6.589: [CMS-concurrent-abortable-preclean: 0.308/1.280 secs] [Times: user=0.72 sys=0.14, real=1.28 secs] 
2020-10-12T20:28:01.146+0800: 6.589: [GC (CMS Final Remark) [YG occupancy: 33649 K (58368 K)]2020-10-12T20:28:01.146+0800: 6.589: [Rescan (parallel) , 0.0047357 secs]2020-10-12T20:28:01.150+0800: 6.594: [weak refs processing, 0.0000330 secs]2020-10-12T20:28:01.151+0800: 6.594: [class unloading, 0.0032122 secs]2020-10-12T20:28:01.154+0800: 6.598: [scrub symbol table, 0.0031940 secs]2020-10-12T20:28:01.157+0800: 6.601: [scrub string table, 0.0003669 secs][1 CMS-remark: 4111K(129728K)] 37760K(188096K), 0.0120370 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.158+0800: 6.602: [CMS-concurrent-sweep-start]
2020-10-12T20:28:01.159+0800: 6.603: [CMS-concurrent-sweep: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:01.159+0800: 6.603: [CMS-concurrent-reset-start]
2020-10-12T20:28:01.162+0800: 6.606: [CMS-concurrent-reset: 0.003/0.003 secs] [Times: user=0.03 sys=0.02, real=0.00 secs] 
2020-10-12T20:28:01.250+0800: 6.694: [GC (Allocation Failure) 2020-10-12T20:28:01.250+0800: 6.694: [ParNew: 56535K->3918K(58368K), 0.0041580 secs] 60532K->8185K(188096K), 0.0042565 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.592+0800: 7.036: [GC (Allocation Failure) 2020-10-12T20:28:01.592+0800: 7.036: [ParNew: 55822K->4870K(58368K), 0.0046292 secs] 60089K->9138K(188096K), 0.0047309 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:01.698+0800: 7.141: [GC (Allocation Failure) 2020-10-12T20:28:01.698+0800: 7.141: [ParNew: 56774K->4910K(58368K), 0.0075001 secs] 61042K->9958K(188096K), 0.0075926 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:01.919+0800: 7.363: [GC (Allocation Failure) 2020-10-12T20:28:01.919+0800: 7.363: [ParNew: 56814K->4181K(58368K), 0.0050461 secs] 61862K->9228K(188096K), 0.0051386 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.096+0800: 7.540: [GC (Allocation Failure) 2020-10-12T20:28:02.096+0800: 7.540: [ParNew: 56085K->4940K(58368K), 0.0060481 secs] 61132K->11188K(188096K), 0.0061327 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.259+0800: 7.703: [GC (Allocation Failure) 2020-10-12T20:28:02.259+0800: 7.703: [ParNew: 56844K->5600K(58368K), 0.0061835 secs] 63092K->12282K(188096K), 0.0062934 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.500+0800: 7.944: [GC (Allocation Failure) 2020-10-12T20:28:02.500+0800: 7.944: [ParNew: 57504K->4325K(58368K), 0.0074456 secs] 64186K->11797K(188096K), 0.0075449 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:02.960+0800: 8.403: [GC (Allocation Failure) 2020-10-12T20:28:02.960+0800: 8.403: [ParNew: 56229K->5301K(58368K), 0.0046992 secs] 63701K->12881K(188096K), 0.0047937 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:03.599+0800: 9.043: [GC (Allocation Failure) 2020-10-12T20:28:03.599+0800: 9.043: [ParNew: 57205K->5776K(58368K), 0.0079695 secs] 64785K->14400K(188096K), 0.0080647 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:03.814+0800: 9.258: [GC (Allocation Failure) 2020-10-12T20:28:03.814+0800: 9.258: [ParNew: 57680K->5516K(58368K), 0.0059135 secs] 66304K->15267K(188096K), 0.0060049 secs] [Times: user=0.05 sys=0.02, real=0.01 secs] 
2020-10-12T20:28:03.964+0800: 9.407: [GC (Allocation Failure) 2020-10-12T20:28:03.964+0800: 9.407: [ParNew: 57420K->3552K(58368K), 0.0049078 secs] 67171K->13747K(188096K), 0.0050155 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:04.140+0800: 9.584: [GC (Allocation Failure) 2020-10-12T20:28:04.140+0800: 9.584: [ParNew: 55456K->4806K(58368K), 0.0080380 secs] 65651K->15000K(188096K), 0.0081439 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:04.979+0800: 10.422: [GC (Allocation Failure) 2020-10-12T20:28:04.979+0800: 10.422: [ParNew: 56710K->6117K(58368K), 0.0064917 secs] 66904K->16828K(188096K), 0.0066100 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.306+0800: 10.751: [GC (Allocation Failure) 2020-10-12T20:28:05.306+0800: 10.751: [ParNew: 58021K->6464K(58368K), 0.0088427 secs] 68732K->19366K(188096K), 0.0089534 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.601+0800: 11.045: [GC (Allocation Failure) 2020-10-12T20:28:05.601+0800: 11.045: [ParNew: 58368K->4962K(58368K), 0.0103327 secs] 71270K->23976K(188096K), 0.0104832 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:05.876+0800: 11.321: [GC (Allocation Failure) 2020-10-12T20:28:05.889+0800: 11.333: [ParNew: 56866K->2053K(58368K), 0.0023822 secs] 75880K->21067K(188096K), 0.0149285 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 
2020-10-12T20:28:06.708+0800: 12.152: [GC (Allocation Failure) 2020-10-12T20:28:06.708+0800: 12.152: [ParNew: 53957K->4781K(58368K), 0.0051989 secs] 72971K->23795K(188096K), 0.0052956 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:06.991+0800: 12.435: [GC (Allocation Failure) 2020-10-12T20:28:06.991+0800: 12.435: [ParNew: 56685K->3541K(58368K), 0.0053836 secs] 75699K->23848K(188096K), 0.0054906 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:07.109+0800: 12.553: [GC (Allocation Failure) 2020-10-12T20:28:07.109+0800: 12.553: [ParNew: 55445K->2720K(58368K), 0.0030331 secs] 75752K->23028K(188096K), 0.0031466 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:07.419+0800: 12.864: [GC (Allocation Failure) 2020-10-12T20:28:07.419+0800: 12.864: [ParNew: 54624K->3846K(58368K), 0.0042669 secs] 74932K->24153K(188096K), 0.0043840 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:07.758+0800: 13.201: [GC (Allocation Failure) 2020-10-12T20:28:07.758+0800: 13.201: [ParNew: 55750K->4086K(58368K), 0.0040793 secs] 76057K->24394K(188096K), 0.0041977 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:08.100+0800: 13.543: [GC (Allocation Failure) 2020-10-12T20:28:08.100+0800: 13.543: [ParNew: 55990K->3118K(58368K), 0.0059216 secs] 76298K->24959K(188096K), 0.0060311 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:08.344+0800: 13.788: [GC (Allocation Failure) 2020-10-12T20:28:08.344+0800: 13.788: [ParNew: 55022K->2554K(58368K), 0.0057652 secs] 76863K->24395K(188096K), 0.0058705 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:08.592+0800: 14.036: [GC (Allocation Failure) 2020-10-12T20:28:08.592+0800: 14.036: [ParNew: 54458K->2927K(58368K), 0.0048231 secs] 76299K->25248K(188096K), 0.0049281 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.060+0800: 14.504: [GC (Allocation Failure) 2020-10-12T20:28:09.060+0800: 14.504: [ParNew: 54831K->3917K(58368K), 0.0059150 secs] 77152K->26402K(188096K), 0.0060336 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.066+0800: 14.510: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22485K(129728K)] 26402K(188096K), 0.0015225 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.068+0800: 14.511: [CMS-concurrent-mark-start]
2020-10-12T20:28:09.118+0800: 14.562: [CMS-concurrent-mark: 0.050/0.051 secs] [Times: user=0.16 sys=0.00, real=0.05 secs] 
2020-10-12T20:28:09.119+0800: 14.562: [CMS-concurrent-preclean-start]
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:09.255+0800: 14.699: [GC (Allocation Failure) 2020-10-12T20:28:09.255+0800: 14.699: [ParNew: 55821K->3271K(58368K), 0.0045993 secs] 78306K->26144K(188096K), 0.0047071 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.429+0800: 14.872: [GC (Allocation Failure) 2020-10-12T20:28:09.429+0800: 14.872: [ParNew: 55175K->4557K(58368K), 0.0050840 secs] 78048K->27692K(188096K), 0.0051880 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.607+0800: 15.052: [CMS-concurrent-abortable-preclean: 0.286/0.488 secs] [Times: user=1.58 sys=0.03, real=0.49 secs] 
2020-10-12T20:28:09.608+0800: 15.052: [GC (CMS Final Remark) [YG occupancy: 56461 K (58368 K)]2020-10-12T20:28:09.608+0800: 15.052: [Rescan (parallel) , 0.0084743 secs]2020-10-12T20:28:09.617+0800: 15.060: [weak refs processing, 0.0000302 secs]2020-10-12T20:28:09.617+0800: 15.060: [class unloading, 0.0077605 secs]2020-10-12T20:28:09.625+0800: 15.068: [scrub symbol table, 0.0105767 secs]2020-10-12T20:28:09.635+0800: 15.079: [scrub string table, 0.0009116 secs][1 CMS-remark: 23134K(129728K)] 79596K(188096K), 0.0284155 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 
2020-10-12T20:28:09.637+0800: 15.080: [CMS-concurrent-sweep-start]
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-sweep: 0.010/0.010 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-reset-start]
2020-10-12T20:28:09.650+0800: 15.094: [CMS-concurrent-reset: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.656+0800: 15.100: [GC (Allocation Failure) 2020-10-12T20:28:09.656+0800: 15.100: [ParNew: 56461K->4964K(58368K), 0.0047764 secs] 77696K->26371K(188096K), 0.0048847 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.800+0800: 15.244: [GC (Allocation Failure) 2020-10-12T20:28:09.800+0800: 15.244: [ParNew: 56868K->4574K(58368K), 0.0053163 secs] 78275K->26318K(188096K), 0.0054317 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.947+0800: 15.391: [GC (Allocation Failure) 2020-10-12T20:28:09.947+0800: 15.392: [ParNew: 56478K->5003K(58368K), 0.0060490 secs] 78222K->27231K(188096K), 0.0062042 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:10.085+0800: 15.528: [GC (Allocation Failure) 2020-10-12T20:28:10.085+0800: 15.528: [ParNew: 56907K->3982K(58368K), 0.0051563 secs] 79135K->26849K(188096K), 0.0052584 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.315+0800: 15.759: [GC (Allocation Failure) 2020-10-12T20:28:10.315+0800: 15.759: [ParNew: 55886K->4953K(58368K), 0.0055548 secs] 78753K->28267K(188096K), 0.0056609 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.478+0800: 15.922: [GC (Allocation Failure) 2020-10-12T20:28:10.479+0800: 15.922: [ParNew: 56857K->4415K(58368K), 0.0075027 secs] 80171K->28582K(188096K), 0.0076109 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:10.602+0800: 16.045: [GC (Allocation Failure) 2020-10-12T20:28:10.602+0800: 16.045: [ParNew: 56319K->3329K(58368K), 0.0046973 secs] 80486K->27932K(188096K), 0.0047916 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:10.709+0800: 16.153: [GC (Allocation Failure) 2020-10-12T20:28:10.709+0800: 16.153: [ParNew: 55233K->3891K(58368K), 0.0043043 secs] 79836K->28976K(188096K), 0.0044113 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:12.027+0800: 17.471: [GC (Allocation Failure) 2020-10-12T20:28:12.027+0800: 17.471: [ParNew: 55795K->3230K(58368K), 0.0047349 secs] 80880K->28650K(188096K), 0.0048530 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:12.178+0800: 17.622: [GC (Allocation Failure) 2020-10-12T20:28:12.178+0800: 17.622: [ParNew: 55134K->4272K(58368K), 0.0050017 secs] 80554K->29974K(188096K), 0.0051122 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.411+0800: 18.854: [GC (Allocation Failure) 2020-10-12T20:28:13.411+0800: 18.854: [ParNew: 56176K->5095K(58368K), 0.0081708 secs] 81878K->31252K(188096K), 0.0083310 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.774+0800: 19.218: [GC (Allocation Failure) 2020-10-12T20:28:13.774+0800: 19.218: [ParNew: 56999K->5067K(58368K), 0.0061007 secs] 83156K->31767K(188096K), 0.0062212 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:13.908+0800: 19.352: [GC (Allocation Failure) 2020-10-12T20:28:13.908+0800: 19.352: [ParNew: 56971K->5604K(58368K), 0.0055308 secs] 83671K->32617K(188096K), 0.0056613 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.025+0800: 19.469: [GC (Allocation Failure) 2020-10-12T20:28:14.025+0800: 19.469: [ParNew: 57508K->5765K(58368K), 0.0062822 secs] 84521K->33182K(188096K), 0.0064433 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.129+0800: 19.573: [GC (Allocation Failure) 2020-10-12T20:28:14.129+0800: 19.573: [ParNew: 57669K->4145K(58368K), 0.0058154 secs] 85086K->32393K(188096K), 0.0059254 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.242+0800: 19.686: [GC (Allocation Failure) 2020-10-12T20:28:14.242+0800: 19.686: [ParNew: 56049K->3992K(58368K), 0.0049823 secs] 84297K->32840K(188096K), 0.0050760 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.407+0800: 19.851: [GC (Allocation Failure) 2020-10-12T20:28:14.407+0800: 19.851: [ParNew: 55896K->3473K(58368K), 0.0048509 secs] 84744K->32969K(188096K), 0.0049603 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.668+0800: 20.112: [GC (Allocation Failure) 2020-10-12T20:28:14.668+0800: 20.112: [ParNew: 55377K->5082K(58368K), 0.0056753 secs] 84873K->35007K(188096K), 0.0057792 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:14.779+0800: 20.223: [GC (Allocation Failure) 2020-10-12T20:28:14.779+0800: 20.223: [ParNew: 56986K->4213K(58368K), 0.0048347 secs] 86911K->34635K(188096K), 0.0049332 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:14.968+0800: 20.412: [GC (Allocation Failure) 2020-10-12T20:28:14.968+0800: 20.412: [ParNew: 56117K->3743K(58368K), 0.0054312 secs] 86539K->34524K(188096K), 0.0055131 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:15.184+0800: 20.628: [GC (Allocation Failure) 2020-10-12T20:28:15.184+0800: 20.628: [ParNew: 55647K->5375K(58368K), 0.0067280 secs] 86428K->36533K(188096K), 0.0068435 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:16.693+0800: 22.137: [GC (Allocation Failure) 2020-10-12T20:28:16.693+0800: 22.137: [ParNew: 57279K->6464K(58368K), 0.0106137 secs] 88437K->38568K(188096K), 0.0107156 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:17.010+0800: 22.454: [GC (Allocation Failure) 2020-10-12T20:28:17.010+0800: 22.454: [ParNew: 58368K->4436K(58368K), 0.0168918 secs] 90472K->41749K(188096K), 0.0170152 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
2020-10-12T20:28:17.248+0800: 22.692: [GC (Allocation Failure) 2020-10-12T20:28:17.248+0800: 22.692: [ParNew: 56340K->1205K(58368K), 0.0019107 secs] 93653K->38518K(188096K), 0.0020041 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:17.519+0800: 22.963: [GC (Allocation Failure) 2020-10-12T20:28:17.519+0800: 22.963: [ParNew: 53109K->2038K(58368K), 0.0027892 secs] 90422K->39350K(188096K), 0.0029034 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 58368K, used 37613K [0x0000000702600000, 0x0000000706550000, 0x00000007172c0000)
  eden space 51904K,  68% used [0x0000000702600000, 0x00000007048bdeb8, 0x00000007058b0000)
  from space 6464K,  31% used [0x00000007058b0000, 0x0000000705aad820, 0x0000000705f00000)
  to   space 6464K,   0% used [0x0000000705f00000, 0x0000000705f00000, 0x0000000706550000)
 concurrent mark-sweep generation total 129728K, used 37312K [0x00000007172c0000, 0x000000071f170000, 0x00000007c0000000)
 Metaspace       used 47336K, capacity 48044K, committed 48352K, reserved 1091584K
  class space    used 6130K, capacity 6317K, committed 6372K, reserved 1048576K

檔案分析:

2020-10-12T20:28:09.066+0800: 14.510: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22485K(129728K)] 26402K(188096K), 0.0015225 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.068+0800: 14.511: [CMS-concurrent-mark-start]
2020-10-12T20:28:09.118+0800: 14.562: [CMS-concurrent-mark: 0.050/0.051 secs] [Times: user=0.16 sys=0.00, real=0.05 secs] 
2020-10-12T20:28:09.119+0800: 14.562: [CMS-concurrent-preclean-start]
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.120+0800: 14.563: [CMS-concurrent-abortable-preclean-start]
2020-10-12T20:28:09.255+0800: 14.699: [GC (Allocation Failure) 2020-10-12T20:28:09.255+0800: 14.699: [ParNew: 55821K->3271K(58368K), 0.0045993 secs] 78306K->26144K(188096K), 0.0047071 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-10-12T20:28:09.429+0800: 14.872: [GC (Allocation Failure) 2020-10-12T20:28:09.429+0800: 14.872: [ParNew: 55175K->4557K(58368K), 0.0050840 secs] 78048K->27692K(188096K), 0.0051880 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.607+0800: 15.052: [CMS-concurrent-abortable-preclean: 0.286/0.488 secs] [Times: user=1.58 sys=0.03, real=0.49 secs] 
2020-10-12T20:28:09.608+0800: 15.052: [GC (CMS Final Remark) [YG occupancy: 56461 K (58368 K)]2020-10-12T20:28:09.608+0800: 15.052: [Rescan (parallel) , 0.0084743 secs]2020-10-12T20:28:09.617+0800: 15.060: [weak refs processing, 0.0000302 secs]2020-10-12T20:28:09.617+0800: 15.060: [class unloading, 0.0077605 secs]2020-10-12T20:28:09.625+0800: 15.068: [scrub symbol table, 0.0105767 secs]2020-10-12T20:28:09.635+0800: 15.079: [scrub string table, 0.0009116 secs][1 CMS-remark: 23134K(129728K)] 79596K(188096K), 0.0284155 secs] [Times: user=0.09 sys=0.00, real=0.03 secs] 
2020-10-12T20:28:09.637+0800: 15.080: [CMS-concurrent-sweep-start]
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-sweep: 0.010/0.010 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2020-10-12T20:28:09.646+0800: 15.090: [CMS-concurrent-reset-start]

這裡是對cms垃圾收集器的一種合理解釋,會發現有多個步驟

6.3.3 G1收集器

生成檔案命令:java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseConcMarkSweepGC -XX:+PrintGCDateStamps -Xloggc:./gc-G1.log -jar jar包包名

紀錄檔分析:
young GC:[GC pause (G1 Evacuation Pause) (young)
initial-mark:[GC pause (Metadata GC Threshold) (young) (initial-mark) (引數:InitiatingHeapOccupancyPercent)
mixed GC:[GC pause (G1 Evacuation Pause) (mixed) (引數:G1HeapWastePercent)
full GC:[Full GC (Allocation Failure) (無可用region)
(G1內部,前面提到的混合GC是非常重要的釋放記憶體機制,它避免了G1出現Region沒有可用的情況,否則就會觸發Full GC事件。
CMS、Parallel、Serial GC都需要通過Full GC去壓縮老年代並在這個過程中掃描整個老年代。G1的Full GC演演算法和Serial GC收集器完全一致。當一個Full GC發生時,整個Java堆執行一個完整的壓縮,這樣確保了最大的空餘記憶體可用。G1的Full GC是一個單執行緒,它可能引起一個長時間的停頓時間,G1的設計目標是減少Full GC,滿足應用效能目標。)

調優方法:
第一次調優,設定Metaspace大小:增大元空間大小-XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M(解釋:原空間會有一個水位線,當原空間大小不足時,原空間會按照一定比例將水位線進行提升,當原空間充足時,水位線會下降,在原空間不足時,適當擴大原空間增加比例,減少專案啟動時間)

第二次調優,新增吞吐量和停頓時間引數:-XX:GCTimeRatio=80 -XX:MaxGCPauseMillis=100 (這就是上邊所講G1的閾值)

7. 虛擬機器器實戰調優總結

調優其實要一定的經驗,本篇文章之舉了簡單的三個調優例子和一些垃圾收集器。垃圾收集器在一定的環境下和不同的記憶體區域(新生代,老年代),jvm會使用不同的垃圾收集器,所以一般情況下我們麼快又必要去更改jdk的jvm垃圾收集器,除非在效能等有極端要求情況下,再去更改垃圾收集器。其他情況下可按照easyGC提出的方案進行引數的調優。筆者對常用的引數在8上進行了總結

8. 虛擬機器器實戰調優調優相關引數

8.1常用引數
a) -XX:+UseG1GC 開啟G1
b) -XX:G1HeapRegionSize=n,region的大小,1-32M,2048個
c) -XX:MaxGCPauseMillis=200 最大停頓時間
d) -XX:G1NewSizePercent -XX:G1MaxNewSizePercent
e) -XX:G1ReservePercent=10 保留防止to space溢位()
f) -XX:ParallelGCThreads=n SWT執行緒數(停止應用程式)
g) -XX:ConcGCThreads=n 並行執行緒數=1/4*並行
8.2最佳實踐
h) 輕代大小:避免使用-Xmn、-XX:NewRatio等顯示設定Young區大小,會覆蓋暫停時間目標(常用引數3)
i) 暫停時間目標:暫停時間不要太嚴苛,其吞吐量目標是90%的應用程式時間和10%的垃圾回收時間,太嚴苛會直接影響到吞吐量
8.3是否需要切換到G1
j) 50%以上的堆被存活物件佔用
k) 物件分配和晉升的速度變化非常大
l) 垃圾回收時間特別長,超過1秒
8.4G1調優目標
m) 6GB以上記憶體
n) 停頓時間是500ms以內
o) 吞吐量是90%以上

8.5 GC常用引數
堆疊設定
-Xss:每個執行緒的棧大小
-Xms:初始堆大小,預設實體記憶體的1/64
-Xmx:最大堆大小,預設實體記憶體的1/4
-Xmn:新生代大小
-XX:NewSize:設定新生代初始大小
-XX:NewRatio:預設2表示新生代佔年老代的1/2,佔整個堆記憶體的1/3。
-XX:SurvivorRatio:預設8表示一個survivor區佔用1/8的Eden記憶體,即1/10的新生代記憶體。
-XX:MetaspaceSize:設定元空間大小
-XX:MaxMetaspaceSize:設定元空間最大允許大小,預設不受限制,JVM Metaspace會進行動態擴充套件。
垃圾回收統計資訊
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-Xloggc:filename
8.6收集器設定
-XX:+UseSerialGC:設定序列收集器
-XX:+UseParallelGC:設定並行收集器
-XX:+UseParallelOldGC:老年代使用並行回收收集器
-XX:+UseParNewGC:在新生代使用並行收集器
-XX:+UseParalledlOldGC:設定並行老年代收集器
-XX:+UseConcMarkSweepGC:設定CMS並行收集器
-XX:+UseG1GC:設定G1收集器
-XX:ParallelGCThreads:設定用於垃圾回收的執行緒數
8.7並行收集器設定
-XX:ParallelGCThreads:設定並行收集器收集時使用的CPU數。並行收集執行緒數。
-XX:MaxGCPauseMillis:設定並行收集最大暫停時間
-XX:GCTimeRatio:設定垃圾回收時間佔程式執行時間的百分比。公式為1/(1+n)
-XX:YoungGenerationSizeIncrement:年輕代gc後擴容比例,預設是20(%)
8.8CMS收集器設定
-XX:+UseConcMarkSweepGC:設定CMS並行收集器
-XX:+CMSIncrementalMode:設定為增量模式。適用於單CPU情況。
-XX:ParallelGCThreads:設定並行收集器新生代收集方式為並行收集時,使用的CPU數。並行收集執行緒數。
-XX:CMSFullGCsBeforeCompaction:設定進行多少次CMS垃圾回收後,進行一次記憶體壓縮
-XX:+CMSClassUnloadingEnabled:允許對類後設資料進行回收
-XX:UseCMSInitiatingOccupancyOnly:表示只在到達閥值的時候,才進行CMS回收
-XX:+CMSIncrementalMode:設定為增量模式。適用於單CPU情況
-XX:ParallelCMSThreads:設定CMS的執行緒數量
-XX:CMSInitiatingOccupancyFraction:設定CMS收集器在老年代空間被使用多少後觸發
-XX:+UseCMSCompactAtFullCollection:設定CMS收集器在完成垃圾收集後是否要進行一次記憶體碎片的整理
8.9G1收集器設定
-XX:+UseG1GC:使用G1收集器
-XX:ParallelGCThreads:指定GC工作的執行緒數量
-XX:G1HeapRegionSize:指定分割區大小(1MB~32MB,且必須是2的冪),預設將整堆劃分為2048個分割區
-XX:GCTimeRatio:吞吐量大小,0-100的整數(預設9),值為n則系統將花費不超過1/(1+n)的時間用於垃圾收集
-XX:MaxGCPauseMillis:目標暫停時間(預設200ms)
-XX:G1NewSizePercent:新生代記憶體初始空間(預設整堆5%)
-XX:G1MaxNewSizePercent:新生代記憶體最大空間
-XX:TargetSurvivorRatio:Survivor填充容量(預設50%)
-XX:MaxTenuringThreshold:最大任期閾值(預設15)
-XX:InitiatingHeapOccupancyPercen:老年代佔用空間超過整堆比IHOP閾值(預設45%),超過則執行混合收集
-XX:G1HeapWastePercent:堆廢物百分比(預設5%)
-XX:G1MixedGCCountTarget:引數混合週期的最大總次數(預設8)