`
85977328
  • 浏览: 1869687 次
  • 性别: Icon_minigender_1
  • 来自: 北京
社区版块
存档分类
最新评论

JVM内存分析系列（十一）GC基本情况与CMS垃圾收集器调优

 
阅读更多
初始标记
CMS-initial-mark
并发标记
CMS-concurrent-mark
CMS-concurrent-preclean
CMS-concurrent-abortable-preclean
重新标记
CMS-remark
并发清理
CMS-concurrent-sweep
重置线程
CMS-concurrent-reset


其中preclean该步用于重新扫描在concurrent mark阶段CMS Heap中被新创建的对象或从新生代晋升到旧生代对象的引用关系，以减少remark所需耗费的时间，这是Sun JDK 1.5后增加的一个优化步骤。

可选参数
-XX:CMSInitiatingOccupancyFraction=85（触发FULL GC的老年代使用百分比）
-XX:CMSFullGCsBeforeCompaction=5（多少次后进行内存压缩）
-XX:ParallelGCThreads=8（并发标记和清除时的线程数）

其他参数
-XX:+UseCMSInitiatingOccupancyOnly 使用手动定义初始化定义开始CMS收集


CMS触发参数与条件（与eden区有关系）
-XX:CMSScheduleRemarkEdenSizeThreshold=2M
-XX:CMSScheduleRemarkEdenPenetration=50
-XX:CMSMaxAbortablePrecleanTime=5000（单位为毫秒）

当eden space占用超过CMSScheduleRemarkEdenSizeThreshold时，执行此步，并且将一直并发的执行到eden space的使用率超过CMSScheduleRemarkEdenPenetration，之后触发remark动作,过CMSMaxAbortablePrecleanTime时间扔为达到要求，则直接触发CMS-remark

常用的优化配置示例 
#!/bin/bash

SERVER_HOME="/application/search/server"
CONF_HOME="/application/search/server/conf"
LOG_HOME="/data0/search/server"
CURRENT_TIME=`date +%Y-%m-%d_%H:%M:%S`

java -server -verbose:gc -Xms512m -Xmx512m -Xmn192m -XX:PermSize=32m -XX:MaxPermSize=32m -Xss256k -XX:+UseConcMarkSweepGC -XX:ParallelGCThreads=4 -XX:+UseCMSCompactAtFullCollection -XX:CMSMaxAbortablePrecleanTime=5000 -XX:CMSFullGCsBeforeCompaction=5 -XX:CMSInitiatingOccupancyFraction=85 -XX:+UseParNewGC -Xloggc:${LOG_HOME}/logs/gc.${CURRENT_TIME}.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=${LOG_HOME}/logs/HeapDumpOnOutOfMemoryError.${CURRENT_TIME}.log -XX:+DisableExplicitGC -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -cp ${SERVER_HOME}/server.jar:${SERVER_HOME}/lib/* -DCONF_HOME=${CONF_HOME} -DLOG_HOME=${LOG_HOME} com.chinaso.search.Server >>${LOG_HOME}/logs/console.log 2>&1 &




案例一：空跑 
package com.chinaso.phl;


/**
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly  
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server0 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
    }

}

/*
Heap
par new generation   total 9216K, used 507K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
 eden space 8192K,   6% used [0x00000000f9a00000, 0x00000000f9a7eee0, 0x00000000fa200000)
 from space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 to   space 1024K,   0% used [0x00000000fa300000, 0x00000000fa300000, 0x00000000fa400000)
concurrent mark-sweep generation total 10240K, used 0K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
concurrent-mark-sweep perm gen total 21248K, used 3033K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/

空跑eclipse的时候，占用了507K的新生代空间，老生代无任何数据。持久代使用了3033K空间。其中默认值遵循了eden:survival=8:1的原则。

案例二：验证对象大小 
package com.chinaso.phl;


/**
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly  
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server1 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(2);
//        System.out.println("minor gc");
//        byte[] b4 = getM(2);
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
Heap
 par new generation   total 9216K, used 6651K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  81% used [0x00000000f9a00000, 0x00000000fa07ef10, 0x00000000fa200000)
  from space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
  to   space 1024K,   0% used [0x00000000fa300000, 0x00000000fa300000, 0x00000000fa400000)
 concurrent mark-sweep generation total 10240K, used 0K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3034K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/

新生代使用的空间为6651K = 507 + 2048 * 3，所以新分配的3个2M对象，占用了6M的空间。但是没有发生GC，如果再分配一个2M对象，就会超出eden空间进行一次minor gc。

案例三：minor GC 
package com.chinaso.phl;

/**
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly  
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server2 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(2);
        System.out.println("minor gc");
        byte[] b4 = getM(2);//执行这一行的时候就会GC
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
minor gc
0.108: [GC 0.109: [ParNew: 6487K->173K(9216K), 0.0048546 secs] 6487K->6319K(19456K), 0.0049077 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 2385K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  27% used [0x00000000f9a00000, 0x00000000f9c28fd8, 0x00000000fa200000)
  from space 1024K,  16% used [0x00000000fa300000, 0x00000000fa32b500, 0x00000000fa400000)
  to   space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 concurrent mark-sweep generation total 10240K, used 6146K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3039K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/

从内容来看，执行了一次新生代的垃圾回收操作。对象占用空间从6487K减少到173K，其中总新生代可用空间（1*eden + 1*survival）即9216K，耗时0.0048546 secs，整个堆内存的情况为闸弄空间从6487K降低到6319K，其中总可用堆大小为19456K。其中查看heap，可知道新生代已用2385K，老生代使用6146K，基本与之前分配的3个2M对象2048*3=6144相等，表明此3个对象进行minor GC后，进入了老年代。而新生代占用的空间2385中，基本与刚分配的第四个2M对象相等。下个实验，我们将触发major GC即：full gc

案例四：major GC
本案例开启参数-XX:+UseCMSInitiatingOccupancyOnly 
package com.chinaso.phl;

import java.util.concurrent.TimeUnit;

/**
 * 案例四：major GC
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly  
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server3 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(2);
        System.out.println("minor gc");
        byte[] b4 = getM(2);//执行这一行的时候就会GC
        TimeUnit.SECONDS.sleep(2);

        byte[] b5 = getM(2);
        byte[] b6 = getM(2);
        System.out.println("promotion failed");
        byte[] b7 = getM(2);
        TimeUnit.SECONDS.sleep(2);
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
minor gc
0.102: [GC 0.102: [ParNew: 6487K->176K(9216K), 0.0049663 secs] 6487K->6322K(19456K), 0.0050174 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
promotion failed
2.110: [GC 2.110: [ParNew: 6570K->6570K(9216K), 0.0000346 secs]2.110: [CMS: 6146K->8192K(10240K), 0.0134294 secs] 12716K->12448K(19456K), [CMS Perm : 3074K->3074K(21248K)], 0.0135341 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2.124: [GC [1 CMS-initial-mark: 8192K(10240K)] 14496K(19456K), 0.0002687 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.125: [CMS-concurrent-mark-start]
2.128: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.128: [CMS-concurrent-preclean-start]
2.130: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
2.130: [CMS-concurrent-abortable-preclean-start]
2.130: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.131: [GC[YG occupancy: 6304 K (9216 K)]2.131: [Rescan (parallel) , 0.0001867 secs]2.131: [weak refs processing, 0.0000054 secs] [1 CMS-remark: 8192K(10240K)] 14496K(19456K), 0.0002429 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.131: [CMS-concurrent-sweep-start]
2.131: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.131: [CMS-concurrent-reset-start]
2.131: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.092: [GC [1 CMS-initial-mark: 8192K(10240K)] 14496K(19456K), 0.0002814 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.093: [CMS-concurrent-mark-start]
4.096: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.096: [CMS-concurrent-preclean-start]
4.096: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.096: [CMS-concurrent-abortable-preclean-start]
4.096: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.096: [GC[YG occupancy: 6304 K (9216 K)]4.096: [Rescan (parallel) , 0.0001894 secs]4.096: [weak refs processing, 0.0000050 secs] [1 CMS-remark: 8192K(10240K)] 14496K(19456K), 0.0002433 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 
4.096: [CMS-concurrent-sweep-start]
4.096: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.096: [CMS-concurrent-reset-start]
4.097: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 6468K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  78% used [0x00000000f9a00000, 0x00000000fa051178, 0x00000000fa200000)
  from space 1024K,   0% used [0x00000000fa300000, 0x00000000fa300000, 0x00000000fa400000)
  to   space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 concurrent mark-sweep generation total 10240K, used 8192K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3082K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/


案例五：major GC
本案例删除参数-XX:+UseCMSInitiatingOccupancyOnly 
package com.chinaso.phl;

import java.util.concurrent.TimeUnit;

/**
 * 案例五：major GC
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server4 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(2);
        System.out.println("minor gc");
        byte[] b4 = getM(2);//执行这一行，minor GC
        TimeUnit.SECONDS.sleep(2);

        byte[] b5 = getM(2);
        byte[] b6 = getM(2);
        System.out.println("promotion failed");
        byte[] b7 = getM(2);//执行这一行，分配担保失败
        TimeUnit.SECONDS.sleep(2);
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
minor gc
0.106: [GC 0.106: [ParNew: 6487K->176K(9216K), 0.0050621 secs] 6487K->6322K(19456K), 0.0051125 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2.111: [GC [1 CMS-initial-mark: 6146K(10240K)] 8620K(19456K), 0.0003830 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.112: [CMS-concurrent-mark-start]
promotion failed
2.115: [GC 2.115: [ParNew: 6570K->6570K(9216K), 0.0000308 secs]2.115: [CMS2.117: [CMS-concurrent-mark: 0.004/0.005 secs] [Times: user=0.00 sys=0.02, real=0.00 secs] 
 (concurrent mode failure): 6146K->8192K(10240K), 0.0144718 secs] 12716K->12448K(19456K), [CMS Perm : 3074K->3074K(21248K)], 0.0145735 secs] [Times: user=0.00 sys=0.02, real=0.01 secs] 
4.094: [GC [1 CMS-initial-mark: 8192K(10240K)] 14496K(19456K), 0.0003338 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.094: [CMS-concurrent-mark-start]
4.098: [CMS-concurrent-mark: 0.004/0.004 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
4.098: [CMS-concurrent-preclean-start]
4.100: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.100: [CMS-concurrent-abortable-preclean-start]
4.100: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.102: [GC[YG occupancy: 6304 K (9216 K)]4.103: [Rescan (parallel) , 0.0001871 secs]4.103: [weak refs processing, 0.0000054 secs] [1 CMS-remark: 8192K(10240K)] 14496K(19456K), 0.0002575 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.103: [CMS-concurrent-sweep-start]
4.103: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.103: [CMS-concurrent-reset-start]
4.103: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 6468K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  78% used [0x00000000f9a00000, 0x00000000fa051178, 0x00000000fa200000)
  from space 1024K,   0% used [0x00000000fa300000, 0x00000000fa300000, 0x00000000fa400000)
  to   space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 concurrent mark-sweep generation total 10240K, used 8192K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3082K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/


案例六：设置CMS的preclean超时触发 
package com.chinaso.phl;

import java.util.concurrent.TimeUnit;

/**
 * 案例六：设置CMS的preclean超时触发
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:CMSMaxAbortablePrecleanTime=5000 -XX:CMSScheduleRemarkEdenSizeThreshold=1M
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server5 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(3);
        System.out.println("minor gc");
        byte[] b4 = getM(1);
        TimeUnit.SECONDS.sleep(8);
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
minor gc
0.199: [GC 0.199: [ParNew: 7511K->176K(9216K), 0.0057871 secs] 7511K->7346K(19456K), 0.0058452 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2.204: [GC [1 CMS-initial-mark: 7170K(10240K)] 8619K(19456K), 0.0004038 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.205: [CMS-concurrent-mark-start]
2.208: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
2.208: [CMS-concurrent-preclean-start]
2.209: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.209: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 7.221: [CMS-concurrent-abortable-preclean: 0.059/5.012 secs] [Times: user=0.05 sys=0.00, real=5.01 secs] 
7.221: [GC[YG occupancy: 1449 K (9216 K)]7.221: [Rescan (parallel) , 0.0001736 secs]7.221: [weak refs processing, 0.0000050 secs] [1 CMS-remark: 7170K(10240K)] 8619K(19456K), 0.0002317 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
7.221: [CMS-concurrent-sweep-start]
7.221: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
7.221: [CMS-concurrent-reset-start]
7.222: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 1613K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  17% used [0x00000000f9a00000, 0x00000000f9b675a8, 0x00000000fa200000)
  from space 1024K,  17% used [0x00000000fa300000, 0x00000000fa32c110, 0x00000000fa400000)
  to   space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 concurrent mark-sweep generation total 10240K, used 7170K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3082K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/

通过启动参数CMSScheduleRemarkEdenSizeThreshold我们可以知道，当eden区使用超过1M的时候，CMS垃圾收集触发以后，就会启动preclean（这个是JDK1.5的新特性），当并发执行到CMSScheduleRemarkEdenPenetration百分比值时候直接触发remark，如果设置了XX:CMSMaxAbortablePrecleanTime，则在CMSMaxAbortablePrecleanTime时间后，直接触发remark，忽略CMSScheduleRemarkEdenPenetration。
其中可以看到 CMS: abort preclean due to time 7.221:表示触发了preclean

案例七：设置CMS的preclean容量触发 
package com.chinaso.phl;

import java.util.concurrent.TimeUnit;

/**
 * 案例七：设置CMS的preclean容量触发
 * -Xms20m -Xmx20m -Xmn10m -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:CMSMaxAbortablePrecleanTime=5000 -XX:CMSScheduleRemarkEdenSizeThreshold=1M -XX:CMSScheduleRemarkEdenPenetration=35
 * @author piaohailin
 * @date   2014-1-15
*/
public class Server6 {

    /**
     * 
     * @param args
     * @author piaohailin
     * @date   2014-1-15
    */
    public static void main(String[] args) throws Exception {
        byte[] b1 = getM(2);
        byte[] b2 = getM(2);
        byte[] b3 = getM(3);
        System.out.println("minor gc");
        byte[] b4 = getM(1);
        TimeUnit.SECONDS.sleep(2);
        byte[] b5 = getM(1);
        TimeUnit.SECONDS.sleep(2);
        byte[] b6 = getM(1);
        TimeUnit.SECONDS.sleep(8);
    }

    public static byte[] getM(int m) {
        return new byte[1024 * 1024 * m];
    }

}
/*
minor gc
0.185: [GC 0.185: [ParNew: 7511K->176K(9216K), 0.0057790 secs] 7511K->7346K(19456K), 0.0058398 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2.191: [GC [1 CMS-initial-mark: 7170K(10240K)] 8619K(19456K), 0.0004258 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.192: [CMS-concurrent-mark-start]
2.195: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.195: [CMS-concurrent-preclean-start]
2.196: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.196: [CMS-concurrent-abortable-preclean-start]
4.216: [CMS-concurrent-abortable-preclean: 0.023/2.020 secs] [Times: user=0.02 sys=0.00, real=2.02 secs] 
4.216: [GC[YG occupancy: 3497 K (9216 K)]4.216: [Rescan (parallel) , 0.0001836 secs]4.216: [weak refs processing, 0.0000058 secs] [1 CMS-remark: 7170K(10240K)] 10667K(19456K), 0.0002418 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.216: [CMS-concurrent-sweep-start]
4.216: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.216: [CMS-concurrent-reset-start]
4.217: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.266: [GC [1 CMS-initial-mark: 7170K(10240K)] 10667K(19456K), 0.0002891 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.266: [CMS-concurrent-mark-start]
4.269: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.269: [CMS-concurrent-preclean-start]
4.269: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.269: [CMS-concurrent-abortable-preclean-start]
4.270: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.270: [GC[YG occupancy: 3497 K (9216 K)]4.270: [Rescan (parallel) , 0.0001925 secs]4.270: [weak refs processing, 0.0000050 secs] [1 CMS-remark: 7170K(10240K)] 10667K(19456K), 0.0002479 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.270: [CMS-concurrent-sweep-start]
4.270: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4.270: [CMS-concurrent-reset-start]
4.270: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.271: [GC [1 CMS-initial-mark: 7170K(10240K)] 10667K(19456K), 0.0003114 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.271: [CMS-concurrent-mark-start]
6.274: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.274: [CMS-concurrent-preclean-start]
6.274: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.274: [CMS-concurrent-abortable-preclean-start]
6.274: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.274: [GC[YG occupancy: 3497 K (9216 K)]6.274: [Rescan (parallel) , 0.0002117 secs]6.275: [weak refs processing, 0.0000042 secs] [1 CMS-remark: 7170K(10240K)] 10667K(19456K), 0.0002752 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.275: [CMS-concurrent-sweep-start]
6.275: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
6.275: [CMS-concurrent-reset-start]
6.275: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.275: [GC [1 CMS-initial-mark: 7170K(10240K)] 10667K(19456K), 0.0002918 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.276: [CMS-concurrent-mark-start]
8.279: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.279: [CMS-concurrent-preclean-start]
8.279: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.279: [CMS-concurrent-abortable-preclean-start]
8.279: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.279: [GC[YG occupancy: 3497 K (9216 K)]8.279: [Rescan (parallel) , 0.0001401 secs]8.279: [weak refs processing, 0.0000042 secs] [1 CMS-remark: 7170K(10240K)] 10667K(19456K), 0.0001936 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.279: [CMS-concurrent-sweep-start]
8.279: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
8.279: [CMS-concurrent-reset-start]
8.280: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.280: [GC [1 CMS-initial-mark: 7170K(10240K)] 10667K(19456K), 0.0003064 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.280: [CMS-concurrent-mark-start]
10.283: [CMS-concurrent-mark: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.283: [CMS-concurrent-preclean-start]
10.283: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.283: [CMS-concurrent-abortable-preclean-start]
10.283: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.283: [GC[YG occupancy: 3497 K (9216 K)]10.283: [Rescan (parallel) , 0.0001428 secs]10.284: [weak refs processing, 0.0000042 secs] [1 CMS-remark: 7170K(10240K)] 10667K(19456K), 0.0001940 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.284: [CMS-concurrent-sweep-start]
10.284: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
10.284: [CMS-concurrent-reset-start]
10.284: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 9216K, used 3661K [0x00000000f9a00000, 0x00000000fa400000, 0x00000000fa400000)
  eden space 8192K,  42% used [0x00000000f9a00000, 0x00000000f9d675c8, 0x00000000fa200000)
  from space 1024K,  17% used [0x00000000fa300000, 0x00000000fa32c110, 0x00000000fa400000)
  to   space 1024K,   0% used [0x00000000fa200000, 0x00000000fa200000, 0x00000000fa300000)
 concurrent mark-sweep generation total 10240K, used 7170K [0x00000000fa400000, 0x00000000fae00000, 0x00000000fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 3082K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
*/

本次实验，设置了XX:CMSScheduleRemarkEdenPenetration=35，只有2秒的时候，优先于-XX:CMSMaxAbortablePrecleanTime=5000设置的5秒触发了remark，可以观察
2.196: [CMS-concurrent-abortable-preclean-start]
4.216: [CMS-concurrent-abortable-preclean: 0.023/2.020 secs] [Times: user=0.02 sys=0.00, real=2.02 secs]
时间停顿有2秒钟。

附录
参考文章
http://www.cnblogs.com/redcreen/archive/2011/05/04/2037057.html
http://szhnet.iteye.com/blog/1423894
http://book.51cto.com/art/201011/235590.htm


文章更新日志
2014-01-24
完善个别CMS参数的说明


作者简介
昵称:澳洲鸟
姓名:朴海林
QQ:85977328
MSN:6301655@163.com
分享到：
| memcached（十六）缓存基本知识
评论
发表评论

您还没有登录,请您登录后再发表评论

相关推荐

    jvm性能调优-垃圾收集器parnew&CMS底层三色标记算-performance-gc-parnew-cms.zip

    jvm性能调优-垃圾收集器parnew&CMS底层三色标记算-performance-gc-parnew-cms

    深入理解JVM内存结构及运行原理全套视频加资料.txt

     第41讲 垃圾收集器-cms收集器详解 00:14:58  第42讲 最牛的垃圾收集器-g1收集器详解 00:18:04  第43讲 内存分配-概述 00:04:23  第44讲 内存分配-Eden区域 00:22:51  第45讲 内存分配-大对象直接进老年代...

    JVM中CMS收集器1

    1. GC事件开始的时间 2. GC开始相对于JVM启动时间时间差 4. 收集原因 5. 使用收集器的名称 6. Young代回收前后的已使用空间 8. 清除时

    04-VIP-JVM垃圾收集器详解1

    1.垃圾收集器 1. -XX:+UseConcMarkSweepGC：启用cms 2. -XX:ConcGCThreads：并发的GC线程数 3. -XX:+U

    降低Java垃圾回收开销的5条建议

    保持GC低开销的窍门有哪些? 　随着一再拖延而即将发布的 Java9，G1(“Garbage First”)垃圾回收器将被成为 HotSpot 虚拟机默认的垃圾回收器。...CMS(“Concurrent Mark-Sweep”)收集器与 parallel GC 相比，它将回收过

    【JVM和性能优化】2.垃圾回收器和内存分配策略

    文章目录内存回收引用计数法可达性分析浅谈引用强引用软引用弱引用虚引用方法区GC 算法标记-清除算法（Mark-Sweep）复制算法（Copying）标记-整理算法（Mark-Compact）GC算法综合用年轻代老年代永久代枚举根节点安全...

    Java虚拟机

    第3章　垃圾收集器与内存分配策略 3.1　概述 3.2　对象已死吗 3.2.1　引用计数算法 3.2.2　可达性分析算法 3.2.3　再谈引用 3.2.4　生存还是死亡 3.2.5　回收方法区 3.3　垃圾收集算法 3.3.1　标记-清除算法 3.3.2　...

    Java后端面试问题整理.docx

    • 熟悉JVM内存区域，常用引用类型，垃圾回收机制、算法以及常见的GC垃圾收集器(Serial、ParNew、Parallel Scavenge、Serial Old、Parallel Old、CMS、G1) • 熟悉常用IO模型(BIO、NIO、AIO)，熟悉JVM类加载过程与...

    JVM大厂高频面试题，连这些都不知道，还敢说自己学过JVM?

    CMS 收集器与 G1 收集器的特点。8. Minor GC 与 Full GC 分别在什么时候发生？9. 几种常用的内存调试工具：jmap、jstack、jconsole、jhat10. 类加载的几个过程：11.JVM 内存分哪几个区，每个区的作用是什么?

    java面试常见基础（深层次，高级研发）

    2.4.3. 并发收集器（响应时间优先） 11 2.4.4. 其它垃圾回收参数 11 2.5. 辅助信息参数设置 12 2.6. 关于参数名称等 13 3. JVM服务参数调优实战 14 3.1. 大型网站服务器案例 14 3.2. 内部集成构建服务器案例 15 4. ...

    verbosegcanalyzer:Java GC日志汇总报告

    仅适用于以下 JVM 参数-verbosegc -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:logs/gc.log和 CMS 收集器。 使用 JDK 6 测试。 #总结报告示例 Total time: 20.51 min Young size ...

    【白雪红叶】JAVA学习技术栈梳理思维导图.xmind

    GC收集器类型 串行 CMS 并行 G1 算法 复制 标记清理 标记整理 分区 新生代 eden survivor 老年代（old区） 永久代（perm区） 版本变化 1.5 1.6 1.7 1.8 1.9 IO/NIO IO类型 同步阻塞 同步非...

    java核心知识点整理.pdf

    JVM 内存区域 ..................................................................................................................................... 21 2.2.1. 程序计数器(线程私有) ........................

    JAVA核心知识点整理(有效)

    2.2. JVM 内存区域 ..................................................................................................................................... 21 2.2.1. 程序计数器(线程私有) ....................

Magicbox
Global site tag (gtag.js) - Google Analytics