CMS日誌

1. GC參數配置

-XX:+PrintGC

輸出GC日誌。

-verbose:gc

能夠認爲 -verbose:gc 是 -XX:+PrintGC 的別名。

-Xloggc:log/gc.log

輸出GC日誌的存儲路徑。

-XX:+PrintGCDetails

輸出GC的詳細日誌。

-XX:+PrintGCDateStamps

輸出GC的時間戳（以日期的形式）。

-XX:+ExplicitGCInvokesConcurrent

不管何時調用系統GC，都執行CMS GC，而不是Full GC。

-XX:+PrintHeapAtGC

在進行GC的先後打印出堆的信息。

-Xms512m

設置初始堆的大小。

-Xmx512m

堆分配的最大空間。

-Xmn1024m

設置年輕代大小。

整個JVM內存大小 = 年輕代大小 + 年老代大小 + 持久代大小，持久代通常固定大小爲64m，因此增大年輕代後，將會減少年老代大小。此值對系統性能影響較大，Sun官方推薦配置爲整個堆的3/8。

-Xss320K

設置每一個線程的堆棧大小。

JDK5.0之後每一個線程堆棧大小爲1M，之前每一個線程堆棧大小爲256K。根據應用的線程所需內存大小進行調整。在相同物理內存下，減少這個值能生成更多的線程。可是操做系統對一個進程內的線程數仍是有限制的，不能無限生成，經驗值在3000~5000左右。

-XX:+UseConcMarkSweepGC

使用CMS收集器，其它相似。

-XX:NewRatio=4

設置年輕代（包括Eden和兩個Survivor區）與年老代的比值（除去持久代）。設置爲4，則年輕代與年老代所佔比值爲1：4，年輕代佔整個堆棧的1/5，默認值是2即老年代是新生代內存的2倍

-XX:SurvivorRatio=4

設置年輕代中Eden區與Survivor區的大小比值。設置爲4，則兩個Survivor區與一個Eden區的比值爲2:4，一個Survivor區佔整個年輕代的1/6，默認值爲8。

-XX:MaxPermSize=16m

設置持久代大小爲16m。

-XX:MaxTenuringThreshold=0

設置垃圾最大年齡。若是設置爲0的話，則年輕代對象不通過Survivor區，直接進入年老代。對於年老代比較多的應用，能夠提升效率。若是將此值設置爲一個較大值，則年輕代對象會在Survivor區進行屢次複製，這樣能夠增長對象再年輕代的存活時間，增長在年輕代即被回收的概論。

GC[Allocation Failure]表示向young generation(eden)給新對象申請空間，可是young generation(eden)剩餘的合適空間不夠所需的大小致使的minor gc。

2. Minor GC: UseParNewGC 回收日誌

2018-12-29T14:39:40.102+0800: 3.856: [GC (Allocation Failure) 2018-12-29T14:39:40.102+0800: 3.856: [ParNew: 681600K->72044K(766784K), 0.0977206 secs] 681600K->72044K(4109120K), 0.0978554 secs] [Times: user=0.39 
sys=0.06, real=0.10 secs]

2018-12-29T14:39:40.102+0800 本次gc觸發的時間；

3.856 jvm啓動後所經歷的秒數；

GC (Allocation Failure) 對象分配在新生代但空間不夠致使觸發一次新生代gc；

ParNew 表示這是新生代gc類型, 即ParNewGC；

681600K->72044K(766784K), 0.0977206 secs 觸發新生代gc時年輕代堆的大小，回收後的年輕代堆的大小，年輕代堆的總大小，該次gc回收所耗費的時間；

681600K->72044K(4109120K) 回收前堆的總大小，回收後堆的總大小，堆的總大小。

3. Major GC: UseConcMarkSweepGC 垃圾收集

CMS垃圾收集器總共分爲7個階段，其中有2個階段，便是初始標記和最終標記階段，是須要暫停用戶線程的，其他垃圾收集線程均與用戶線程併發執行。

CMS垃圾收集器在新版本的 Java 中被標記爲棄用，後續的垃圾收集器默認使用G1GC。但目前很大一部分的垃圾收集器依然是CMS，故須要瞭解一下CMS垃圾收集的一些流程。

3.1 Phase 1: Initial Mark 初始標記

2018-12-29T14:46:45.247+0800: 429.000: [GC (CMS Initial Mark) [1 CMS-initial-mark: 17305K(3342336K)] 607785K(4109120K), 0.0704856 secs] [Times: user=0.32 sys=0.10, real=0.07 secs]

這是CMS中兩次stop-the-world事件中的一次。它有兩個目標：一是標記老年代中全部的GC Roots；二是標記被年輕代中活着的對象引用的對象；

[1 CMS-initial-mark 收集階段，開始收集全部的GC Roots和直接引用到的對象；

17305K(3342336K) 當前老年代的使用狀況，老年代可用容量；

607785K(4109120K) 當前整個堆的使用狀況，整個堆的容量，便是整個堆 - 老年代 = 新生代(4109120 - 3342336 = 766784)。

3.2 Phase 2: Concurrent Mark 併發標記

2018-12-29T14:46:45.317+0800: 429.071: [CMS-concurrent-mark-start]
2018-12-29T14:46:45.326+0800: 429.080: [CMS-concurrent-mark: 0.009/0.009 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

這個階段會遍歷整個老年代而且標記全部存活的對象，從「初始化標記」階段找到的GC Roots開始。併發標記的特色是和應用程序線程同時運行。並非老年代的全部存活對象都會被標記，由於標記的同時應用程序會改變一些對象的引用等；

CMS-concurrent-mark 併發收集階段，這個階段會遍歷整個年老代而且標記活着的對象。

0.009/0.009 secs 展現該階段持續的時間和時鐘時間。

3.3 Phase 3: Concurrent Preclean 併發預清除

2018-12-29T14:46:45.326+0800: 429.080: [CMS-concurrent-preclean-start]
2018-12-29T14:46:45.338+0800: 429.092: [CMS-concurrent-preclean: 0.012/0.012 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

這個階段又是一個併發階段，和應用線程並行運行，不會中斷他們。前一個階段在並行運行的時候，一些對象的引用已經發生了變化，當這些引用發生變化的時候，JVM會標記堆的這個區域爲Dirty Card(包含被標記可是改變了的對象，被認爲"dirty")，這就是 Card Marking；

在pre-clean階段，那些可以從dirty card對象到達的對象也會被標記，這個標記作完以後，dirty card標記就會被清除了；

一些必要的清掃工做也會作，還會作一些final remark階段須要的準備工做；

CMS-concurrent-preclean 這個階段負責前一個階段標記了又發生改變的對象標記。

3.4 Phase 4: Concurrent Abortable Preclean 可終止的併發預清理

2018-12-29T14:46:45.338+0800: 429.092: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2018-12-29T14:46:50.484+0800: 434.238: [CMS-concurrent-abortable-preclean: 4.232/5.146 secs] [Times: user=5.49 sys=0.10, real=5.15 secs]

又一個併發階段不會中止應用程序線程。這個階段嘗試着去承擔STW的Final Remark階段足夠多的工做。這個階段持續的時間依賴好多的因素，因爲這個階段是重複的作相同的事情直到發生aboart的條件（好比：重複的次數、多少許的工做、持續的時間等等）之一纔會中止；

CMS-concurrent-abortable-preclean 可終止的併發預清理；

這個階段很大程度的影響着即未來臨的Final Remark的停頓，有至關一部分重要的 configuration options 和 失敗的模式。

3.5 Phase 5: Final Remark 最終標記

2018-12-29T14:46:50.485+0800: 434.239: [GC (CMS Final Remark) [YG occupancy: 632074 K (766784 K)]2018-12-29T14:46:50.485+0800: 434.239: [Rescan (parallel) , 0.0791637 secs]2018-12-29T14:46:50.564+0800: 434.318: 
[weak refs processing, 0.0001243 secs]2018-12-29T14:46:50.565+0800: 434.318: [class unloading, 0.0409380 secs]2018-12-29T14:46:50.605+0800: 434.359: [scrub symbol table, 0.0136356 secs]2018-12-29T14:46:50.619+08
00: 434.373: [scrub string table, 0.0015586 secs][1 CMS-remark: 17305K(3342336K)] 649380K(4109120K), 0.1370772 secs] [Times: user=0.46 sys=0.06, real=0.13 secs]

這個階段是CMS中第二個而且是最後一個STW的階段。該階段的任務是完成標記整個年老代的全部的存活對象。因爲以前的預處理是併發的，它可能跟不上應用程序改變的速度，這個時候，STW是很是須要的來完成這個嚴酷考驗的階段；

一般CMS儘可能運行Final Remark階段在年輕代是足夠乾淨的時候，目的是消除緊接着的連續的幾個STW階段；

CMS Final Remark 收集階段，這個階段會標記老年代所有的存活對象，包括那些在併發標記階段更改的或者新建立的引用對象；

YG occupancy: 632074 K (766784 K) 年輕代當前佔用的狀況和容量；

Rescan (parallel) 這個階段在應用中止的階段完成存活對象的標記工做；

weak refs processing 第一個子階段，隨着這個階段的進行處理弱引用；

class unloading 第二個子階段, 類的卸載；

scrub symbol table 最後一個子階段, 清理字符引用等；

1 CMS-remark: 17305K(3342336K) 在這個階段以後老年代佔有的內存大小和老年代的容量；

649380K(4109120K) 在這個階段以後整個堆的內存大小和整個堆的容量；

經過以上5個階段的標記，老年代全部存活的對象已經被標記而且如今要經過Garbage Collector採用清掃的方式回收那些不能用的對象了。

3.6 Phase 6: Concurrent Sweep 併發清除

2018-12-29T14:46:50.622+0800: 434.376: [CMS-concurrent-sweep-start]
2018-12-29T14:46:50.635+0800: 434.388: [CMS-concurrent-sweep: 0.012/0.012 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

和應用線程同時進行，不須要STW。這個階段的目的就是移除那些不用的對象，回收他們佔用的空間而且爲未來使用；

CMS-concurrent-sweep 這個階段主要是清除那些沒有標記的對象而且回收空間。

3.7 Phase 7: Concurrent Reset 併發重置

2018-12-29T14:46:50.635+0800: 434.388: [CMS-concurrent-reset-start]
2018-12-29T14:46:50.651+0800: 434.405: [CMS-concurrent-reset: 0.016/0.016 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

這個階段併發執行，從新設置CMS算法內部的數據結構，準備下一個CMS生命週期的使用；

CMS-concurrent-reset 這個階段從新設置CMS算法內部的數據結構，爲下一個收集階段作準備；

可參考JVM調優——之CMS GC日誌分析。