JVM之GC日志

?

JVM 相關(guān)的理論知識網(wǎng)上已經(jīng)被講的比較詳細(xì)了，但是，不管是日常工作或是面試考察，越來越多的開始關(guān)注相關(guān)的實戰(zhàn)經(jīng)驗。所以，小弟希望可以從之前的工作經(jīng)歷和前人的總結(jié)中，講述一些 jvm 實際操作相關(guān)的知識，包括但不限于 GC 日志解析、GC 時間異常相關(guān)實例和發(fā)生原因、OOM 等 jvm 相關(guān)異常等等~不定時更新吧~ 大家一起交流。?

讓程序按期望GC

為了方便我們查看 GC 日志，我們來寫個方便 GC 發(fā)生的程序，參見《深入理解 java 虛擬機(jī)》

private static final int _1MB = 1024 * 1024;

  public static void main(String[] args) {

    MyObject ob1, ob2, ob3, ob4,ob5;

    ob1 = new MyObject("ob1",2 * _1MB);
    ob2 = new MyObject("ob2",2 * _1MB);
    ob3 = new MyObject("ob3",2 * _1MB);
    ob4 = new MyObject("ob4",2 * _1MB);
  }

  privatestaticclass MyObject{
    private String name;
    privatebyte[] space;
    public MyObject(String name, int size) {
      this.name = name;
      this.space = newbyte[size];
      System.out.println(name + " init ~");
    }
  }

我們這里除了真正的內(nèi)存占用的 space，還加上了 name 來標(biāo)示對象順序，雖然內(nèi)存占用會不太準(zhǔn)確，但應(yīng)該是不影響我們對 gc 的理解的。

而運行時的 vm operation 我們設(shè)置為：

-Xms20M
-Xmx20M
-XX:NewSize=10M
-XX:+PrintGCDetails
-XX:SurvivorRatio=8

從理論上分析，因為我們 young 區(qū)設(shè)置了 10M，而 eden 區(qū)和 S 區(qū)的占比為 8:1，因此 eden 區(qū)應(yīng)該是 8M, 兩個 S 區(qū)分別都是 1M。

當(dāng)我們連續(xù)創(chuàng)建了三個 2M 的對象之后，在創(chuàng)建第四個對象時，發(fā)現(xiàn)，eden 區(qū)放不下了，因此觸發(fā)一次 young gc,實際運行后的 GC 日志如下：

ob1 init ~
ob2 init ~
ob3 init ~
[GC (Allocation Failure) [PSYoungGen: 8046K->594K(9216K)] 8046K->6746K(19456K), 0.0030729 secs][times: user=0.01 sys=0.01, real=0.00 secs]
[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)] [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]
ob4 init ~
Heap
PSYoungGen total 9216K, used 2289K [0x00000007bf600000, 0x00000007c0000000, 0x00000007c0000000)
eden space 8192K, 27% used [0x00000007bf600000,0x00000007bf83c460,0x00000007bfe00000)
from space 1024K, 0% used [0x00000007bfe00000,0x00000007bfe00000,0x00000007bff00000)
to space 1024K, 0% used [0x00000007bff00000,0x00000007bff00000,0x00000007c0000000)
ParOldGen total 10240K, used 6642K [0x00000007bec00000, 0x00000007bf600000, 0x00000007bf600000)
object space 10240K, 64% used [0x00000007bec00000,0x00000007bf27cad8,0x00000007bf600000)
Metaspace used 3095K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 339K, capacity 388K, committed 512K, reserved 1048576K

我們可以看到，在 ob3 init 之后， 確實進(jìn)行了 GC，不過是一次 ygc，一次 fgc ,姑且不管 fgc 發(fā)生的原因，我們先來解析一下 GC 日志

young gc 日志解析

[GC (Allocation Failure) [PSYoungGen: 8046K->594K(9216K)] 8046K->6746K(19456K), 0.0030729 secs][times: user=0.01 sys=0.01, real=0.00 secs]

• [GC(Allocation Failure)

   GC類型(GC原因) ，Allocation Failure基本都是空間不夠，是正常的

• [PSYoungGen: 8046K->594K(9216K)]

   GC策略:gc前內(nèi)存占用->gc后內(nèi)存占用（新生代總大小）

• 8046K->6746K(19456K)

   gc前->gc后jvm堆內(nèi)存占用（jvm堆大小）

• 0.0030729 secs

   GC耗時

• [times: user=0.01 sys=0.01, real=0.00 secs]

   [用戶耗時，系統(tǒng)耗時，實際耗時]

full gc 日志解析

full gc 和 young gc 的日志基本上差不多的

[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)]         [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]
[gc類型   (gc原因)      [ygc策略]:young區(qū)gc前后變化(young總大小)] [fgc策略：old區(qū)gc前后(old區(qū)總大小)] jvm堆gc前后變化(堆總大小),[元數(shù)據(jù)區(qū)信息],                    fgc耗時         [gc耗時詳細(xì)信息]

看懂GC日志有什么用

GC日志是很多jvm問題排查和定位的第一道工具。

比如 如果我們發(fā)現(xiàn)old區(qū)上升較快，s區(qū)卻沒有變化，是不是可以猜測是s區(qū)大小設(shè)置的和當(dāng)前系統(tǒng)的對象大小不合適，導(dǎo)致沒有進(jìn)過s區(qū)的年代晉升直接到了老年代；

又或者我們發(fā)現(xiàn)頻繁fgc, gc日志中fgc之后 堆大小變化不大，是不是可以從內(nèi)存泄露這個方向去分析dump文件。

又或者我們在進(jìn)行了一系列業(yè)務(wù)邏輯優(yōu)化后，系統(tǒng)的響應(yīng)任然不盡人意，碰巧公司暫時還沒有成熟的監(jiān)控平臺，那從GC日志的耗時分析出發(fā)，就成了分析問題的必然之路了。

歡迎提交主題，提供更多文章示例~~

補充：為啥ygc之后緊著著一次fgc

最后大概解釋下上述代碼，為啥緊跟著一次fgc呢

GC的擔(dān)保策略，其實是根據(jù)使用的gc策略而略有不同的，我們上述沒有顯示設(shè)置GC策略，那么在1.8的server模式下就默認(rèn)使用了parallel scavenge +parallel old收集器，其擔(dān)保策略規(guī)定：如果老生代的剩余空間少于下一次收集所需的剩余空間，那么現(xiàn)在就做一個完整的收集 。

那么問題來了，我們每個對象大約2M多，三個升到old的話其實也有剩余空間的，為啥就被判斷成不足了呢，這個應(yīng)該是gc策略在計算晉升對象平均值的時候，使用了加權(quán)平均的方法，其中的權(quán)重應(yīng)該是倍數(shù)的，這樣是對未來可能晉升對象所需空間的比較安全的估計，因此，有可能得到了剩余空間不足以下次晉升的結(jié)論。

補充：GC原因都有哪些

除了文中打印出的這兩種，其實還有很多，有興趣的同學(xué)可以看下"gc/shared/gcCause.hpp"  其中的判斷分支應(yīng)該都有一一對應(yīng)

現(xiàn)代jdk的gc日志，進(jìn)化的很好了應(yīng)該已經(jīng)，基本上看展示出來的gc原因也可以猜個大概。