JDK 6 update 14のG1GCを試してみた

さすがにまだJConsoleもVisualVMも対応してない。JConsoleで繋ぐとヒープがまったくないように表示されてフシギな感じ。

結論

ちゃんとオプションが効いて、停止時間もオプションで指定した通りになっているみたい。
けど、TomcatでG1GCを有効にして実行したときは、オプションで指定した停止時間以上に止まっちゃってた。こっちはもうちょっと調査。

G1GCを有効にするためには

以下のオプションをつければOK

 -XX:+UnlockExperimentalVMOptions \
 -XX:+UseG1GC \
 -XX:MaxGCPauseMillis=100

だけど、JMXでの監視がまだできないので昔ながらの方法でgcログを吐かせる。

 -XX:+UnlockExperimentalVMOptions \
 -XX:+UseG1GC \
 -XX:MaxGCPauseMillis=100 \
 -XX:+PrintGC \
 -XX:+PrintGCDetails \
 -XX:+PrintGCTimeStamps \
 -XX:+PrintHeapAtGC \
 -XX:+PrintTenuringDistribution \
 -XX:+TraceGen0Time \
 -XX:+TraceGen1Time \
 -Xloggc:.\gc.log

試したコード

メモリに積みまくる、みたいな。http://itpro.nikkeibp.co.jp/article/COLUMN/20061006/250084/からコピってきたやつ。

import java.util.List;
import java.util.ArrayList;

public class OutOfMemorySample2 {
    private static final String FORMULA = "Hello, World! ";
    private List messages = new ArrayList();

    public OutOfMemorySample2() {
        while(true) {
            appendMessage();

            try {
                Thread.sleep(1L);
            } catch (InterruptedException ex) {
                break;
            }
        }
    }

    private void appendMessage() {
        messages.add(FORMULA);
    }

    public static void main(String[] args) {
        new OutOfMemorySample2();
    }
}

結果のgcのログの最後のサマリのところ

うん。Full GCのところは100ms以下になってる。けど、このログのちゃんと見方がわかってないので、そこから勉強しないと。

ALL PAUSES
   Total                    =     0.48 s (avg =    16.09 ms)
                  (num =    30, std dev =     5.80 ms, max =    35.24 ms)


   Full Young GC Pauses:          29
   Partial Young GC Pauses:        1

EVACUATION PAUSES
   Evacuation Pauses        =     0.48 s (avg =    16.09 ms)
                  (num =    30, std dev =     5.80 ms, max =    35.24 ms)
      SATB Drain               =     0.00 s (avg =     0.00 ms)
      Parallel Time            =     0.47 s (avg =    15.62 ms)
         Update RS                =     0.08 s (avg =     2.74 ms)
         Ext Root Scanning        =     0.07 s (avg =     2.39 ms)
         Mark Stack Scanning      =     0.00 s (avg =     0.00 ms)
         Scan-Only Scanning       =     0.00 s (avg =     0.00 ms)
         Scan RS                  =     0.00 s (avg =     0.07 ms)
         Object Copy              =     0.28 s (avg =     9.40 ms)
         Termination              =     0.01 s (avg =     0.19 ms)
         Other                    =     0.02 s (avg =     0.83 ms)
      Mark Closure             =     0.00 s (avg =     0.00 ms)
      Clear CT                 =     0.00 s (avg =     0.10 ms)
      Other                    =     0.01 s (avg =     0.38 ms)

ABANDONED PAUSES
   none

MISC
   Stop World               =     0.02 s (avg =     0.78 ms)
                  (num =    30, std dev =     0.23 ms, max =     1.26 ms)
   Yields                   =     0.00 s (avg =     0.00 ms)
                  (num =     0, std dev =     0.00 ms, max =     0.00 ms)
   New Regions      682, Young      682 (100.00%), Tenured        0 (  0.00%)

   1 full_gcs: total time =     0.08 s (avg =    75.59ms).
                     [std. dev =     0.00 ms, max =    75.59 ms]