結束 tac 線程阻塞 clas jvm調優 ica esc oid 日誌

一、調優參數設置

JVM的GC日誌的主要參數包括如下幾個：

-XX:+PrintGC 輸出GC日誌

-XX:+PrintGCDetails 輸出GC的詳細日誌

-XX:+PrintGCTimeStamps 輸出GC的時間戳（以基準時間的形式）

-XX:+PrintGCDateStamps 輸出GC的時間戳（以日期的形式，如 2013-05-04T21:53:59.234+0800）

-XX:+PrintHeapAtGC 在進行GC的前後打印出堆的信息

-XX:+PrintGCApplicationStoppedTime // 輸出GC造成應用暫停的時間

-Xloggc:../logs/gc.log 日誌文件的輸出路徑

分析gc日誌後，經常需要調整jvm內存相關參數，常用參數如下：

-Xms：初始堆大小，默認為物理內存的1/64(<1GB)；默認(MinHeapFreeRatio參數可以調整)空余堆內存小於40%時，JVM就會增大堆直到-Xmx的最大限制
-Xmx：最大堆大小，默認(MaxHeapFreeRatio參數可以調整)空余堆內存大於70%時，JVM會減少堆直到 -Xms的最小限制
-Xmn：新生代的內存空間大小，註意：此處的大小是（eden+ 2 survivor space)。與jmap -heap中顯示的New gen是不同的。整個堆大小=新生代大小 + 老生代大小 + 永久代大小。
在保證堆大小不變的情況下，增大新生代後,將會減小老生代大小

。此值對系統性能影響較大,Sun官方推薦配置為整個堆的3/8。
-XX:SurvivorRatio：新生代中Eden區域與Survivor區域的容量比值，默認值為8。兩個Survivor區與一個Eden區的比值為2:8,一個Survivor區占整個年輕代的1/10。
-Xss：每個線程的堆棧大小。JDK5.0以後每個線程堆棧大小為1M,以前每個線程堆棧大小為256K。應根據應用的線程所需內存大小進行適當調整。在相同物理內存下,減小這個值能生成更多的線程。但是操作系統對一個進程內的線程數還是有限制的，不能無限生成，經驗值在3000~5000左右。一般小的應用， 如果棧不是很深， 應該是128k夠用的，大的應用建議使用256k。這個選項對性能影響比較大，需要嚴格的測試。和threadstacksize選項解釋很類似,官方文檔似乎沒有解釋,在論壇中有這樣一句話:"-Xss is translated in a VM flag named ThreadStackSize”一般設置這個值就可以了。
-XX:PermSize：設置永久代(perm gen)初始值。默認值為物理內存的1/64。
-XX:MaxPermSize：設置持久代最大值。物理內存的1/4。

在我做了如下的設置

-XX:+PrintGCDetails -Xloggc:../logs/gc.log -XX:+PrintGCTimeStamps

以後打印出來的日誌為：

 

 
0.756: [Full GC (System) 0.756: [CMS: 0K->1696K(204800K), 0.0347096 secs] 11488K->1696K(252608K), [CMS Perm : 10328K->10320K(131072K)], 0.0347949 secs] [Times: user=0.06 sys=0.00, real=0.05 secs]
 
1.728: [GC 1.728: [ParNew: 38272K->2323K(47808K), 0.0092276 secs] 39968K->4019K(252608K), 0.0093169 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
 
2.642: [GC 2.643: [ParNew: 40595K->3685K(47808K), 0.0075343 secs] 42291K->5381K(252608K), 0.0075972 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
 
4.349: [GC 4.349: [ParNew: 41957K->5024K(47808K), 0.0106558 secs] 43653K->6720K(252608K), 0.0107390 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
 
5.617: [GC 5.617: [ParNew: 43296K->7006K(47808K), 0.0136826 secs] 44992K->8702K(252608K), 0.0137904 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
 
7.429: [GC 7.429: [ParNew: 45278K->6723K(47808K), 0.0251993 secs] 46974K->10551K(252608K), 0.0252421 secs]

我們取倒數第二條記錄分析一下各個字段都代表了什麽含義

5.617（時間戳）: [GC（Young GC） 5.617（時間戳）: [ParNew（GC的區域）: 43296K（垃圾回收前的大小）->7006K（垃圾回收以後的大小）(47808K)（該區域總大小）, 0.0136826 secs（回收時間）] 44992K（堆區垃圾回收前的大小）->8702K（堆區垃圾回收後的大小）(252608K)（堆區總大小）, 0.0137904 secs（回收時間）] [Times: user=0.03（GC用戶耗時） sys=0.00（GC系統耗時）, real=0.02 secs（GC實際耗時）]

我們再對數據做一個簡單的分析

從最後一條GC記錄中我們可以看到 Young GC回收了 45278-6723=38555K的內存

Heap區通過這次回收總共減少了 46974-10551=36423K的內存。

38555-36423=2132K說明通過該次Young GC有2132K的內存被移動到了Old Gen，

我們來驗證一下

在最後一次Young GC的回收以前 Old Gen的大小為8702-7006=1696

回收以後Old Gen的內存使用為10551-6723=3828

Old Gen在該次Young GC以後內存增加了3828-1696=2132K 與預計的相符

4.231: [GC 4.231: [DefNew: 4928K->512K(4928K), 0.0044047 secs] 6835K->3468K(15872K), 0.0045291 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
 
4.445: [Full GC (System) 4.445: [Tenured: 2956K->3043K(10944K), 0.1869806 secs] 4034K->3043K(15872K), [Perm : 3400K->3400K(12288K)], 0.1870847 secs] [Times: user=0.05 sys=0.00, real=0.19 secs]

最前面的數字 4.231 和 4.445 代表虛擬機啟動以來的秒數。

[GC 和 [Full GC 是垃圾回收的停頓類型，而不是區分是新生代還是年老代，如果有 Full 說明發生了Stop-The-World 。如果是調用 System.gc() 觸發的，那麽將顯示的是 [Full GC (System) 。

接下來的 [DefNew, [Tenured, [Perm 表示 GC 發生的區域，區域的名稱與使用的 GC 收集器相關。
Serial 收集器中新生代名為 “Default New Generation”，顯示的名字為 “[DefNew”。對於ParNew收集器，顯示的是 “[ParNew”，表示 “Parallel New Generation”。 對於 Parallel Scavenge 收集器，新生代名為 “PSYoungGen”。年老代和永久代也相同，名稱都由收集器決定。

方括號內部顯示的 “4928K->512K(4928K)” 表示 “GC 前該區域已使用容量 -> GC 後該區域已使用容量 (該區域內存總容量) ”。

再往後的 “0.0044047 secs” 表示該區域GC所用時間，單位是秒。

再往後的 “6835K->3468K(15872K)” 表示 “GC 前Java堆已使用容量 -> GC後Java堆已使用容量 （Java堆總容量）”。

再往後的 “0.0045291 secs” 是Java堆GC所用的總時間。

最後的 “[Times: user=0.00 sys=0.00, real=0.00 secs]” 分別代表 用戶態消耗的CPU時間、內核態消耗的CPU時間 和 操作從開始到結束所經過的墻鐘時間。墻鐘時間包括各種非運算的等待耗時，如IO等待、線程阻塞。CPU時間不包括等待時間，當系統有多核時，多線程操作會疊加這些CPU時間，所以user或sys時間會超過real時間。

堆的分代機制

• young區域就是新生代，存放新創建對象；
• tenured是年老代，存放在新生代經歷多次垃圾回收後仍存活的對象；
• perm是永生代，存放類定義信息、元數據等信息。

當GC發生在新生代時，稱為Minor GC，次收集；當GC發生在年老代時，稱為Major GC，主收集。 一般的，Minor GC的發生頻率要比Major GC高很多。

重新設置GC日誌的輸出

 
-XX:+PrintGCDetails
 
-XX:+PrintHeapAtGC
 
-XX:+PrintGCDateStamps
 
-XX:+PrintTenuringDistribution
 
-verbose:gc
 
-Xloggc:gc.log

後可以看到進行GC前後的堆內存信息

{
Heap before GC invocations=1 (full 0):
 
PSYoungGen total 152896K, used 131072K [0x00000000f5560000, 0x0000000100000000, 0x0000000100000000)
 
eden space 131072K, 100% used [0x00000000f5560000,0x00000000fd560000,0x00000000fd560000)
 
from space 21824K, 0% used [0x00000000feab0000,0x00000000feab0000,0x0000000100000000)
 
to space 21824K, 0% used [0x00000000fd560000,0x00000000fd560000,0x00000000feab0000)
 
PSOldGen total 349568K, used 0K [0x00000000e0000000, 0x00000000f5560000, 0x00000000f5560000)
 
object space 349568K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000f5560000)
 
PSPermGen total 26432K, used 26393K [0x00000000d0000000, 0x00000000d19d0000, 0x00000000e0000000)
 
object space 26432K, 99% used [0x00000000d0000000,0x00000000d19c64a0,0x00000000d19d0000)
 
2013-05-05T23:16:10.480+0800: 5.228: [GC Desired survivor size 22347776 bytes, new threshold 7 (max 15)
 
[PSYoungGen: 131072K->8319K(152896K)] 131072K->8319K(502464K), 0.0176346 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
 
Heap after GC invocations=1 (full 0):
 
PSYoungGen total 152896K, used 8319K [0x00000000f5560000, 0x0000000100000000, 0x0000000100000000)
 
eden space 131072K, 0% used [0x00000000f5560000,0x00000000f5560000,0x00000000fd560000)
 
from space 21824K, 38% used [0x00000000fd560000,0x00000000fdd7ff78,0x00000000feab0000)
 
to space 21824K, 0% used [0x00000000feab0000,0x00000000feab0000,0x0000000100000000)
 
PSOldGen total 349568K, used 0K [0x00000000e0000000, 0x00000000f5560000, 0x00000000f5560000)
 
object space 349568K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000f5560000)
 
PSPermGen total 26432K, used 26393K [0x00000000d0000000, 0x00000000d19d0000, 0x00000000e0000000)
 
object space 26432K, 99% used [0x00000000d0000000,0x00000000d19c64a0,0x00000000d19d0000)
 
}

可以看出前後回收掉了 131072K - 21824K*0.38 = 122778K 內存

示例代碼

/**
 * VM agrs: -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails
 * -XX:SurvivorRatio=8 -XX:+UseSerialGC
 */

public class MinorGCTest {
    private static final int _1MB = 1024 * 1024;

    public static void testAllocation() {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB];
    }

    public static void main(String[] agrs) {
        testAllocation();
    }
}

• VM參數說明

Option	Description
-verbose:gc	顯示GC的操作內容
-Xms20M -Xmx20M	設置堆大小為20M
-Xmn10M	設置新生代的內存空間大小為10M
-XX:+PrintGCDetails	打印GC中的變化
-XX:SurvivorRatio=8	新生代中Eden區域與Survivor區域的大小比值
-XX:+UseSerialGC	在新生代和老年代中使用串行收集器，由於-verbose:gc參數對Parallel Scavenge收集器不起作用，無法顯示顯示GC的操作內容，因此采用串行收集器

• 示例代碼說明
• 該段代碼一共創建了4個數組對象，在給allocation4分配空間前的內存空間使用情況如下： eden區為8M 兩個Survivor為各占1M，年老代占10M。

• 需要執行一次MinorGC才能給allocation4分配空間（Eden區滿時），分配成功以後內存空間使用情況如下：

2. GC日誌

• [GC [DefNew ... ...]

• GC日誌開頭的信息通過設置-verbose:gc參數後才能輸出。

• "[GC"和"[Full GC"說明這次垃圾收集的停頓類型，如果這次GC發生了Stop-The-World，則為"[Full GC"，否則為"[GC"

• "[DefNew "表示GC發生的區域為Serial收集器的新生代中，DefNew是"Default New Generation"的縮寫。Serial收集器的老年代和永久代分別表示為"Tenured"、"Perm"

• ** eden space 8192K, 52% used**

• 新生代的Eden區總共大小為8MB，使用掉的4MB是用來存放allocation4對象

• tenured generation total 10240K, used 6144K

• 老年代大小為10MB，使用掉的6MB是用來存放allocation1、allocation2和allocation3這3個對象

　　中間的Survivor區域占用了19%的內存 此處筆者不是很明白，如果有知道的網友可以給我留言，幫助講解一下，謝謝！

三、內存分配的原則

對象優先分配在Eden區上

虛擬機參數為“-verbose:gc -XX:+PrintGCDetails -Xms20M -Xmx20M -Xmn10M -XX:SurvivorRatio=8”，即10M新生代，10M老年代，10M新生代中8M的Eden區，兩個Survivor區各1M。代碼都是同一段

public class EdenAllocationTest
{
    private static final int _1MB = 1024 * 1024;
    
    public static void main(String[] args)
    {
        byte[] allocation1 = new byte[2 * _1MB];
        byte[] allocation2 = new byte[2 * _1MB];
        byte[] allocation3 = new byte[2 * _1MB];
        byte[] allocation4 = new byte[4 * _1MB];
    }
}

Client模式下

[GC [DefNew: 6487K->194K(9216K), 0.0042856 secs] 6487K->6338K(19456K), 0.0043281 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 def new generation   total 9216K, used 4454K [0x0000000005180000, 0x0000000005b80000, 0x0000000005b80000)
  eden space 8192K,  52% used [0x0000000005180000, 0x00000000055a9018, 0x0000000005980000)
  from space 1024K,  18% used [0x0000000005a80000, 0x0000000005ab0810, 0x0000000005b80000)
  to   space 1024K,   0% used [0x0000000005980000, 0x0000000005980000, 0x0000000005a80000)
 tenured generation   total 10240K, used 6144K [0x0000000005b80000, 0x0000000006580000, 0x0000000006580000)
   the space 10240K,  60% used [0x0000000005b80000, 0x0000000006180048, 0x0000000006180200, 0x0000000006580000)
 compacting perm gen  total 21248K, used 2982K [0x0000000006580000, 0x0000000007a40000, 0x000000000b980000)
   the space 21248K,  14% used [0x0000000006580000, 0x0000000006869890, 0x0000000006869a00, 0x0000000007a40000)
No shared spaces configured.

Server模式下

Heap
 PSYoungGen      total 9216K, used 6651K [0x000000000af20000, 0x000000000b920000, 0x000000000b920000)
  eden space 8192K, 81% used [0x000000000af20000,0x000000000b59ef70,0x000000000b720000)
  from space 1024K, 0% used [0x000000000b820000,0x000000000b820000,0x000000000b920000)
  to   space 1024K, 0% used [0x000000000b720000,0x000000000b720000,0x000000000b820000)
 PSOldGen        total 10240K, used 4096K [0x000000000a520000, 0x000000000af20000, 0x000000000af20000)
  object space 10240K, 40% used [0x000000000a520000,0x000000000a920018,0x000000000af20000)
 PSPermGen       total 21248K, used 2972K [0x0000000005120000, 0x00000000065e0000, 0x000000000a520000)
  object space 21248K, 13% used [0x0000000005120000,0x0000000005407388,0x00000000065e0000)

看到在Client模式下，最後分配的4M在新生代中，先分配的6M在老年代中；

在Server模式下，最後分配的4M在老年代中，先分配的6M在新生代中。說明不同的垃圾收集器組合對於對象的分配是有影響的。

講下兩者差別的原因：

1、Client模式下，新生代分配了6M，虛擬機在GC前有6487K，比6M也就是6144K多，多主要是因為TLAB和EdenAllocationTest這個對象占的空間，TLAB可以通過“-XX:+PrintTLAB”這個虛擬機參數來查看大小。

OK，6M多了，然後來了一個4M的，Eden+一個Survivor總共就9M不夠分配了【感覺這個地方說的有點不對，因為觸發一次Minor GC的情況是是Eden內存滿，這裏不應該把Survivor算進去】，這時候就會觸發一次Minor GC。但是觸發Minor GC也沒用，因為allocation1、allocation2、allocation3三個引用還存在，另一塊1M的Survivor也不夠放下這6M，那麽這次Minor GC的效果其實是通過分配擔保機制將這6M的內容轉入老年代中。然後再來一個4M的，此時Minor GC之後新生代只剩下了194K了，夠分配了，所以4M順利進入新生代。

2、Server模式下，前面都一樣，但是在GC的時候有一點區別。在GC前還會進行一次判斷，如果要分配的內存>=Eden區大小的一半，那麽會直接把要分配的內存放入老年代中。要分配4M，Eden區8M，剛好一半，而且老年代10M，夠分配，所以4M就直接進入老年代去了。為了驗證一下結論，我們把3個2M之後分配的4M改為3M看一下。

public class EdenAllocationTest
{
    private static final int _1MB = 1024 * 1024;
    
    public static void main(String[] args)
    {
        byte[] allocation1 = new byte[2 * _1MB];
        byte[] allocation2 = new byte[2 * _1MB];
        byte[] allocation3 = new byte[2 * _1MB];
        byte[] allocation4 = new byte[3 * _1MB];
    }
}

運行結果為

[GC [PSYoungGen: 6487K->352K(9216K)] 6487K->6496K(19456K), 0.0035661 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC [PSYoungGen: 352K->0K(9216K)] [PSOldGen: 6144K->6338K(10240K)] 6496K->6338K(19456K) [PSPermGen: 2941K->2941K(21248K)], 0.0035258 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
Heap
 PSYoungGen      total 9216K, used 3236K [0x000000000af40000, 0x000000000b940000, 0x000000000b940000)
  eden space 8192K, 39% used [0x000000000af40000,0x000000000b269018,0x000000000b740000)
  from space 1024K, 0% used [0x000000000b740000,0x000000000b740000,0x000000000b840000)
  to   space 1024K, 0% used [0x000000000b840000,0x000000000b840000,0x000000000b940000)
 PSOldGen        total 10240K, used 6338K [0x000000000a540000, 0x000000000af40000, 0x000000000af40000)
  object space 10240K, 61% used [0x000000000a540000,0x000000000ab70858,0x000000000af40000)
 PSPermGen       total 21248K, used 2982K [0x0000000005140000, 0x0000000006600000, 0x000000000a540000)
  object space 21248K, 14% used [0x0000000005140000,0x0000000005429890,0x0000000006600000)

看到3M在新生代中，6M通過分配擔保機制進入老年代了。

大對象直接進入老年代

虛擬機參數為“-XX:+PrintGCDetails -Xms20M -Xmx20M -Xmn10M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=3145728”，最後那個參數表示大於這個設置值的對象直接在老年代中分配，這樣做的目的是為了避免在Eden區和兩個Survivor區之間發生大量的內存復制。測試代碼為

public class OldTest
{
    private static final int _1MB = 1024 * 1024;
    
    public static void main(String[] args)
    {
         byte[] allocation = new byte[4 * _1MB];
    }
}

Client模式下

Heap
 def new generation   total 9216K, used 507K [0x0000000005140000, 0x0000000005b40000, 0x0000000005b40000)
  eden space 8192K,   6% used [0x0000000005140000, 0x00000000051bef28, 0x0000000005940000)
  from space 1024K,   0% used [0x0000000005940000, 0x0000000005940000, 0x0000000005a40000)
  to   space 1024K,   0% used [0x0000000005a40000, 0x0000000005a40000, 0x0000000005b40000)
 tenured generation   total 10240K, used 4096K [0x0000000005b40000, 0x0000000006540000, 0x0000000006540000)
   the space 10240K,  40% used [0x0000000005b40000, 0x0000000005f40018, 0x0000000005f40200, 0x0000000006540000)
 compacting perm gen  total 21248K, used 2972K [0x0000000006540000, 0x0000000007a00000, 0x000000000b940000)
   the space 21248K,  13% used [0x0000000006540000, 0x00000000068272a0, 0x0000000006827400, 0x0000000007a00000)
No shared spaces configured.

Server模式下

Heap
 PSYoungGen      total 9216K, used 4603K [0x000000000afc0000, 0x000000000b9c0000, 0x000000000b9c0000)
  eden space 8192K, 56% used [0x000000000afc0000,0x000000000b43ef40,0x000000000b7c0000)
  from space 1024K, 0% used [0x000000000b8c0000,0x000000000b8c0000,0x000000000b9c0000)
  to   space 1024K, 0% used [0x000000000b7c0000,0x000000000b7c0000,0x000000000b8c0000)
 PSOldGen        total 10240K, used 0K [0x000000000a5c0000, 0x000000000afc0000, 0x000000000afc0000)
  object space 10240K, 0% used [0x000000000a5c0000,0x000000000a5c0000,0x000000000afc0000)
 PSPermGen       total 21248K, used 2972K [0x00000000051c0000, 0x0000000006680000, 0x000000000a5c0000)
  object space 21248K, 13% used [0x00000000051c0000,0x00000000054a72a0,0x0000000006680000)

看到Client模式下4M直接進入了老年代，Server模式下4M還在新生代中。產生這個差別的原因是“-XX:PretenureSizeThreshold”這個參數對Serial+Serial Old垃圾收集器組合有效而對Parallel+Serial Old垃圾收集器組合無效。

其他幾條原則

上面列舉的原則其實不重要，只是演示罷了，也不需要記住，因為實際過程中我們可能使用的並不是上面的垃圾收集器的組合，可能使用ParNew垃圾收集器，可能使用G1垃圾收集器。場景很多，重要的是要在實際使用的時候有辦法知道使用的垃圾收集器對於對象分配有哪些原則，因為理解這些原則才是調優的第一步。下面列舉一下對象分配的另外兩條原則：

1、長期存活的對象將進入老年代。Eden區中的對象在一次Minor GC後沒有被回收，則對象年齡+1，當對象年齡達到“-XX:MaxTenuringThreshold”設置的值的時候，對象就會被晉升到老年代中

2、Survivor空間中相同年齡的所有對象大小總和大於Survivor空間的一半，年齡大於或等於該年齡的對象就可以直接進入老年代，無須等到“-XX:MaxTenuringThreshold”設置要求的年齡

JVM調優日誌解析分析與性能監控工具