當一個URL被通路時，記憶體申請過程 如下：
A. JVM會試圖為相關Java對象在Eden中初始化一塊記憶體區域
B. 當Eden空間足夠時，記憶體申請結束。否則到下一步
C. JVM試圖釋放在Eden中所有不活躍的對象（這屬于1或更進階的垃圾回收）, 釋放後若Eden空間仍然不足以放入新對象，則試圖将部分Eden中活躍對象放入Survivor區
D. Survivor區被用來作為Eden及OLD的中間交換區域，當OLD區空間足夠時，Survivor區的對象會被移到Old區，否則會被保留在Survivor區
E. 當OLD區空間不夠時，JVM會在OLD區進行完全的垃圾收集（0級）
F. 完全垃圾收集後，若Survivor及OLD區仍然無法存放從Eden複制過來的部分對象，導緻JVM無法在Eden區為新對象建立記憶體區域，則出現”out of memory錯誤”
對象衰老的過程
young generation的記憶體，由一塊Eden(伊甸園，有意思)和兩塊Survivor Space(1.4文檔中稱為semi-space)構成。新建立的對象的記憶體都配置設定自eden。兩塊Survivor Space總有會一塊是空閑的，用作copying collection的目标空間。Minor collection的過程就是将eden和在用survivor space中的活對象copy到空閑survivor space中。所謂survivor，也就是大部分對象在伊甸園出生後，根本活不過一次GC。對象在young generation裡經曆了一定次數的minor collection後，年紀大了，就會被移到old generation中，稱為tenuring。(是否僅當survivor space不足的時候才會将老對象tenuring? 目前資料中沒有找到描述)
剩餘記憶體空間不足會觸發GC，如eden空間不夠了就要進行minor collection，old generation空間不夠要進行major collection，permanent generation空間不足會引發full GC。
SUN JDK監控與故障處理工具
jps:顯示制定系統内所有的HotSpot虛拟機程序
jstat：用于收集HotSpot虛拟機各方面的運作資料
jstat
jstat是vm的狀态監控工具，監控的内容有類加載、運作時編譯及GC。
使用時，需加上檢視程序的程序id，和所選參數。以下詳細介紹各個參數的意義。
jstat -class pid:顯示加載class的數量，及所占空間等資訊。
jstat -compiler pid:顯示VM實時編譯的數量等資訊。
jstat -gc pid:可以顯示gc的資訊，檢視gc的次數，及時間。其中最後五項，分别是young gc的次數，young gc的時間，full gc的次數，full gc的時間，gc的總時間。
jstat -gccapacity:可以顯示，VM記憶體中三代（young,old,perm）對象的使用和占用大小，如：PGCMN顯示的是最小perm的記憶體使用量，PGCMX顯示的是perm的記憶體最大使用量，PGC是目前新生成的perm記憶體占用量，PC是但前perm記憶體占用量。其他的可以根據這個類推， OC是old内純的占用量。
jstat -gcnew pid:new對象的資訊。
jstat -gcnewcapacity pid:new對象的資訊及其占用量。
jstat -gcold pid:old對象的資訊。
jstat -gcoldcapacity pid:old對象的資訊及其占用量。
jstat -gcpermcapacity pid: perm對象的資訊及其占用量。
jstat -util pid:統計gc資訊統計。
jstat -printcompilation pid:目前VM執行的資訊。
除了以上一個參數外，還可以同時加上 兩個數字，如：jstat -printcompilation 3024 250 6是每250毫秒列印一次，一共列印6次，還可以加上-h3每三行顯示一下标題。
jinfo:顯示虛拟機配置資訊
jmap:生成虛拟機的記憶體轉儲快照
jhat:用于分析heapdump檔案，讓使用者可以在浏覽器上檢視分析結果
jstack:顯示jvm的線程快照。
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 | Statistics on the behavior of the garbage collected heap |
|gccapacity | Statistics of the capacities of the generations and their |
| | corresponding spaces. |
|gccause | 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- |
| | sponding spaces. |
|gcold | 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 每秒向标準輸出輸出一行新内容, 比如:
Timestamp S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
200.0 8448.0 8448.0 8448.0 0.0 67712.0 67712.0 169344.0 169344.0 21248.0 20534.3 3072.0 2807.7 34 0.720 658 133.684 134.404
201.0 8448.0 8448.0 8448.0 0.0 67712.0 67712.0 169344.0 169343.2 21248.0 20534.3 3072.0 2807.7 34 0.720 662 134.712 135.432
202.0 8448.0 8448.0 8102.5 0.0 67712.0 67598.5 169344.0 169343.6 21248.0 20534.3 3072.0 2807.7 34 0.720 667 135.840 136.559
203.0 8448.0 8448.0 8126.3 0.0 67712.0 67702.2 169344.0 169343.6 21248.0 20547.2 3072.0 2807.7 34 0.720 669 136.178 136.898
204.0 8448.0 8448.0 8126.3 0.0 67712.0 67702.2 169344.0 169343.6 21248.0 20547.2 3072.0 2807.7 34 0.720 669 136.178 136.898
205.0 8448.0 8448.0 8134.6 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 671 136.234 136.954
206.0 8448.0 8448.0 8134.6 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 671 136.234 136.954
207.0 8448.0 8448.0 8154.8 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 673 136.289 137.009
208.0 8448.0 8448.0 8154.8 0.0 67712.0 67712.0 169344.0 169343.5 21248.0 20547.2 3072.0 2807.7 34 0.720 673 136.289 137.009
- 上面的内容。參考 jstat manpage , 我們可以知道:
- jstat 連接配接到 JVM 的時間, 是JVM啟動後的 200秒。此資訊從第一行的 “Timestamp” 列得知。繼續看下一行, jstat 每秒鐘從JVM 接收一次資訊, 也就是指令行參數中 “
1s
- 從第一行的 “YGC” 列得知年輕代共執行了34次GC, 由 “FGC” 列得知整個堆記憶體已經執行了 658次 full GC。
- 年輕代的GC耗時總共為
0.720 秒
- Full GC 的總計耗時為
133.684 秒
再看下一行, 問題就更明顯了。
- 在接下來的一秒内共執行了 4 次 Full GC。參見 “FGC” 列.
- 這4次 Full GC 暫停占用了差不多 1秒的時間(根據 FGCT列的差得知)。與第一行相比, Full GC 耗費了
928 毫秒
92.8%
- 根據 “OC 和 “OU” 列得知, 整個老年代的空間為
169,344.0 KB
169,344.2 KB
928ms
隻看這兩行的内容, 就知道程式出了很嚴重的問題。繼續分析下一行, 可以确定問題依然存在,而且變得更糟。
JVM幾乎完全卡住了(stalled), 因為GC占用了90%以上的計算資源。GC之後, 所有的老代空間仍然還在占用。事實上, 程式在一分鐘以後就挂了, 抛出了 “java.lang.OutOfMemoryError: GC overhead limit exceeded” 錯誤。
可以看到, 通過 jstat 能很快發現對JVM健康極為不利的GC行為。一般來說, 隻看 jstat 的輸出就能快速發現以下問題:
- 最後一列 “GCT”, 與JVM的總運作時間 “Timestamp” 的比值, 就是GC 的開銷。如果每一秒内, “GCT” 的值都會明顯增大, 與總運作時間相比, 就暴露出GC開銷過大的問題. 不同系統對GC開銷有不同的容忍度, 由性能需求決定, 一般來講, 超過
10%
- “YGC” 和 “FGC” 列的快速變化往往也是有問題的征兆。頻繁的GC暫停會累積,并導緻更多的線程停頓(stop-the-world pauses), 進而影響吞吐量。
- 如果看到 “OU” 列中,老年代的使用量約等于老年代的最大容量(OC), 并且不降低的話, 就表示雖然執行了老年代GC, 但基本上屬于無效GC。
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 輸出的日志類似這樣:
199.879: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1473386 secs] [Times: user=0.43 sys=0.01, real=0.15 secs]
200.027: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1567794 secs] [Times: user=0.41 sys=0.00, real=0.16 secs]
200.184: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1621946 secs] [Times: user=0.43 sys=0.00, real=0.16 secs]
200.346: [Full GC (Ergonomics) [PSYoungGen: 64000K->63998K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1547695 secs] [Times: user=0.41 sys=0.00, real=0.15 secs]
200.502: [Full GC (Ergonomics) [PSYoungGen: 64000K->63999K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1563071 secs] [Times: user=0.42 sys=0.01, real=0.16 secs]
200.659: [Full GC (Ergonomics) [PSYoungGen: 64000K->63999K(74240K)] [ParOldGen: 169318K->169318K(169472K)] 233318K->233317K(243712K), [Metaspace: 20427K->20427K(1067008K)], 0.1538778 secs] [Times: user=0.42 sys=0.00, real=0.16 secs]
在 “04. GC算法:實作篇” 中詳細介紹了這些格式, 如果對此不了解, 可以先閱讀該章節。
分析以上日志内容, 可以得知:
- 這部分日志截取自JVM啟動後200秒左右。
- 日志片段中顯示, 在
780毫秒
- 這些暫停事件的總持續時間是
777毫秒
- 在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%
- 極個别的GC事件暫停時間過長。當某次GC暫停時間太長, 就會影響系統的延遲名額. 如果延遲名額規定交易必須在
1,000 ms
1000毫秒
- 老年代的使用量超過限制。如果老年代空間在 Full GC 之後仍然接近全滿, 那麼GC就成為了性能瓶頸, 可能是記憶體太小, 也可能是存在記憶體洩漏。這種症狀會讓GC的開銷暴增。
可以看到,GC日志中的資訊非常詳細。但除了這些簡單的小程式, 生産系統一般都會生成大量的GC日志, 純靠人工是很難閱讀和進行解析的。
GCViewer
我們可以自己編寫解析器, 來将龐大的GC日志解析為直覺易讀的圖形資訊。 但很多時候自己寫程式也不是個好辦法, 因為各種GC算法的複雜性, 導緻日志資訊格式互相之間不太相容。那麼神器來了: GCViewer。
GCViewer 是一款開源的GC日志分析工具。項目的 GitHub 首頁對各項名額進行了完整的描述. 下面我們介紹最常用的一些名額。
第一步是擷取GC日志檔案。這些日志檔案要能夠反映系統在性能調優時的具體場景. 假若營運部門(operational department)回報: 每周五下午,系統就運作緩慢, 不管GC是不是主要原因, 分析周一早晨的日志是沒有多少意義的。
擷取到日志檔案之後, 就可以用 GCViewer 進行分析, 大緻會看到類似下面的圖形界面:
使用的指令行大緻如下:
java -jar gcviewer_1.3.4.jar gc.log
當然, 如果不想打開程式界面,也可以在後面加上其他參數,直接将分析結果輸出到檔案。
指令大緻如下:
java -jar gcviewer_1.3.4.jar gc.log summary.csv chart.png
以上指令将資訊彙總到目前目錄下的 Excel 檔案
summary.csv
之中, 将圖形資訊儲存為
chart.png
檔案。
點選下載下傳: gcviewer的jar包及使用示例 。
上圖中, Chart 區域是對GC事件的圖形化展示。包括各個記憶體池的大小和GC事件。上圖中, 隻有兩個可視化名額: 藍色線條表示堆記憶體的使用情況, 黑色的Bar則表示每次GC暫停時間的長短。
從圖中可以看到, 記憶體使用量增長很快。一分鐘左右就達到了堆記憶體的最大值. 堆記憶體幾乎全部被消耗, 不能順利配置設定新對象, 并引發頻繁的 Full GC 事件. 這說明程式可能存在記憶體洩露, 或者啟動時指定的記憶體空間不足。
從圖中還可以看到 GC暫停的頻率和持續時間。
30秒
之後, GC幾乎不間斷地運作,最長的暫停時間超過
1.4秒
。
在右邊有三個頁籤。“
Summary
(摘要)” 中比較有用的是 “
Throughput
”(吞吐量百分比) 和 “
Number of GC pauses
”(GC暫停的次數), 以及“
Number of full GC pauses
”(Full GC 暫停的次數). 吞吐量顯示了有效工作的時間比例, 剩下的部分就是GC的消耗。
以上示例中的吞吐量為
6.28%
。這意味着有
93.72%
的CPU時間用在了GC上面. 很明顯系統所面臨的情況很糟糕 —— 寶貴的CPU時間沒有用于執行實際工作, 而是在試圖清理垃圾。
下一個有意思的地方是“Pause”(暫停)頁籤:
“
Pause
” 展示了GC暫停的總時間,平均值,最小值和最大值, 并且将 total 與minor/major 暫停分開統計。如果要優化程式的延遲名額, 這些統計可以很快判斷出暫停時間是否過長。另外, 我們可以得出明确的資訊: 累計暫停時間為
634.59 秒
, GC暫停的總次數為
3,938 次
, 這在
11分鐘/660秒
的總運作時間裡那不是一般的高。
更詳細的GC暫停彙總資訊, 請檢視主界面中的 “Event details” 标簽:
從“Event details” 标簽中, 可以看到日志中所有重要的GC事件彙總:
普通GC停頓
和
Full GC 停頓次數
, 以及
并發執行數
,
非 stop-the-world 事件
等。此示例中, 可以看到一個明顯的地方, Full GC 暫停嚴重影響了吞吐量和延遲, 依據是:
3,928 次 Full GC
, 暫停了
634秒
。
可以看到, GCViewer 能用圖形界面快速展現異常的GC行為。一般來說, 圖像化資訊能迅速揭示以下症狀:
- 低吞吐量。當應用的吞吐量下降到不能容忍的地步時, 有用工作的總時間就大量減少. 具體有多大的 “容忍度”(tolerable) 取決于具體場景。按照經驗, 低于 90% 的有效時間就值得警惕了, 可能需要好好優化下GC。
- 單次GC的暫停時間過長。隻要有一次GC停頓時間過長,就會影響程式的延遲名額. 例如, 延遲需求規定必須在 1000 ms以内完成交易, 那就不能容忍任何一次GC暫停超過1000毫秒。
- 堆記憶體使用率過高。如果老年代空間在 Full GC 之後仍然接近全滿, 程式性能就會大幅降低, 可能是資源不足或者記憶體洩漏。這種症狀會對吞吐量産生嚴重影響。
業界良心 —— 圖形化展示的GC日志資訊絕對是我們重磅推薦的。不用去閱讀冗長而又複雜的GC日志,通過容易了解的圖形, 也可以得到同樣的資訊。
首先需要注意的是在對JVM記憶體調優的時候不能隻看作業系統級别Java程序所占用的記憶體，這個數值不能準确的反應堆記憶體的真實占用情況，因為GC過後這個值是不會變化的，是以記憶體調優的時候要更多地使用JDK提供的記憶體檢視工具，比如JConsole和Java VisualVM。
對JVM記憶體的系統級的調優主要的目的是減少GC的頻率和Full GC的次數，過多的GC和Full GC是會占用很多的系統資源（主要是CPU），影響系統的吞吐量。特别要關注Full GC，因為它會對整個堆進行整理，導緻Full GC一般由于以下幾種情況：
-
舊生代空間不足
調優時盡量讓對象在新生代GC時被回收、讓對象在新生代多存活一段時間和不要建立過大的對象及數組避免直接在舊生代建立對象
-
Pemanet Generation空間不足
增大Perm Gen空間，避免太多靜态對象
-
統計得到的GC後晉升到舊生代的平均大小大于舊生代剩餘空間
控制好新生代和舊生代的比例
-
System.gc()被顯示調用
垃圾回收不要手動觸發，盡量依靠JVM自身的機制
調優手段主要是通過控制堆記憶體的各個部分的比例和GC政策來實作，下面來看看各部分比例不良設定會導緻什麼後果
1）新生代設定過小
一是新生代GC次數非常頻繁，增大系統消耗；二是導緻大對象直接進入舊生代，占據了舊生代剩餘空間，誘發Full GC
2）新生代設定過大
一是新生代設定過大會導緻舊生代過小（堆總量一定），進而誘發Full GC；二是新生代GC耗時大幅度增加
一般說來新生代占整個堆1/3比較合适
3）Survivor設定過小
導緻對象從eden直接到達舊生代，降低了在新生代的存活時間
4）Survivor設定過大
導緻eden過小，增加了GC頻率
另外，通過-XX:MaxTenuringThreshold=n來控制新生代存活時間，盡量讓對象在新生代被回收
可知新生代和舊生代都有多種GC政策群組合搭配，選擇這些政策對于我們這些開發人員是個難題，JVM提供兩種較為簡單的GC政策的設定方式
1）吞吐量優先
JVM以吞吐量為名額，自行選擇相應的GC政策及控制新生代與舊生代的大小比例，來達到吞吐量名額。這個值可由-XX:GCTimeRatio=n來設定
2）暫停時間優先
JVM以暫停時間為名額，自行選擇相應的GC政策及控制新生代與舊生代的大小比例，盡量保證每次GC造成的應用停止時間都在指定的數值範圍内完成。這個值可由-XX:MaxGCPauseRatio=n來設定
最後彙總一下JVM常見配置
- 堆設定
- -Xms:初始堆大小
- -Xmx:最大堆大小
- -XX:NewSize=n:設定年輕代大小
- -XX:NewRatio=n:設定年輕代和年老代的比值。如:為3，表示年輕代與年老代比值為1：3，年輕代占整個年輕代年老代和的1/4
- -XX:SurvivorRatio=n:年輕代中Eden區與兩個Survivor區的比值。注意Survivor區有兩個。如：3，表示Eden：Survivor=3：2，一個Survivor區占整個年輕代的1/5
- -XX:MaxPermSize=n:設定持久代大小
- 收集器設定
- -XX:+UseSerialGC:設定串行收集器
- -XX:+UseParallelGC:設定并行收集器
- -XX:+UseParalledlOldGC:設定并行年老代收集器
- -XX:+UseConcMarkSweepGC:設定并發收集器
- 垃圾回收統計資訊
- -XX:+PrintGC
- -XX:+PrintGCDetails
- -XX:+PrintGCTimeStamps
- -Xloggc:filename
- 并行收集器設定
- -XX:ParallelGCThreads=n:設定并行收集器收集時使用的CPU數。并行收集線程數。
- -XX:MaxGCPauseMillis=n:設定并行收集最大暫停時間
- -XX:GCTimeRatio=n:設定垃圾回收時間占程式運作時間的百分比。公式為1/(1+n)
- 并發收集器設定
- -XX:+CMSIncrementalMode:設定為增量模式。适用于單CPU情況。
- -XX:ParallelGCThreads=n:設定并發收集器年輕代收集方式為并行收集時，使用的CPU數。并行收集線程數
參考資料：https://blog.csdn.net/renfufei/article/details/56678064
https://blog.csdn.net/cutesource/article/details/5907418