GC Log的一些疑问

xm_king 2012-10-24
在Eclipse中运行下面的代码,JDK的版本是1.6.25
public class GCDemo {
	/**
	 * -Xms20m -Xmx20m -Xmn10m -XX:+UseSerialGC -XX:SurvivorRatio=3 -XX:+PrintGCDetails
	 */
    public static void main(String[] args) throws Exception{

        byte[] bytes1 = new byte[1024*1024*2];
        byte[] bytes2 = new byte[1024*1024*1];
        byte[] bytes3 = new byte[1024*512];
        bytes1 = null;
        byte[] bytes4 = new byte[1024*1024*3];
        
    }
}

打印出的GC日志是
[GC [DefNew: 3845K->1684K(8192K), 0.0019665 secs] 3845K->1684K(18432K), 0.0019953 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
def new generation   total 8192K, used 5002K [0x326d0000, 0x330d0000, 0x330d0000)
  eden space 6144K,  54% used [0x326d0000, 0x32a0d7f8, 0x32cd0000)
  from space 2048K,  82% used [0x32ed0000, 0x330753f0, 0x330d0000)
  to   space 2048K,   0% used [0x32cd0000, 0x32cd0000, 0x32ed0000)
tenured generation   total 10240K, used 0K [0x330d0000, 0x33ad0000, 0x33ad0000)
   the space 10240K,   0% used [0x330d0000, 0x330d0000, 0x330d0200, 0x33ad0000)
compacting perm gen  total 12288K, used 371K [0x33ad0000, 0x346d0000, 0x37ad0000)
   the space 12288K,   3% used [0x33ad0000, 0x33b2cd98, 0x33b2ce00, 0x346d0000)
    ro space 10240K,  54% used [0x37ad0000, 0x3804e770, 0x3804e800, 0x384d0000)
    rw space 12288K,  55% used [0x384d0000, 0x38b74ac8, 0x38b74c00, 0x390d0000)
这个比较好理解,byte1被回收,bytes2、bytes3被放入到survior的from区,bytes4被分配在Eden区。
然后,在加上下面的一段代码,VM参数不变

public class GCDemo {
	/**
	 * -Xms20m -Xmx20m -Xmn10m -XX:+UseSerialGC -XX:SurvivorRatio=3 -XX:+PrintGCDetails
	 */
    public static void main(String[] args) throws Exception{

        byte[] bytes1 = new byte[1024*1024*2];
        byte[] bytes2 = new byte[1024*1024*1];
        byte[] bytes3 = new byte[1024*512];
        bytes1 = null;
        byte[] bytes4 = new byte[1024*1024*3];
        
        byte[] bytes5 = new byte[1024*1024];
        bytes2 = null;
        bytes4 = null;
        byte[] bytes6 = new byte[1024*1024*2];
        
    }
}

接着上面的例子,分配了一个1MB的bytes5,这时候Eden的大小为4MB了,然后bytes2、bytes4的引用为空,在分配一个2MB的bytes6对象,按照我的理解,bytes2和bytes4将要被回收,bytes5和在From区的bytes3对象拷贝到To区,bytes6分配在Eden区。但是打印出来的日志却不是这样的:

[GC [DefNew: 3845K->1684K(8192K), 0.0028850 secs] 3845K->1684K(18432K), 0.0029137 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC [DefNew: 5969K->1024K(8192K), 0.0019443 secs] 5969K->1684K(18432K), 0.0019689 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
def new generation   total 8192K, used 3195K [0x326d0000, 0x330d0000, 0x330d0000)
  eden space 6144K,  35% used [0x326d0000, 0x328eec08, 0x32cd0000)
  from space 2048K,  50% used [0x32cd0000, 0x32dd0098, 0x32ed0000)
  to   space 2048K,   0% used [0x32ed0000, 0x32ed0000, 0x330d0000)
tenured generation   total 10240K, used 660K [0x330d0000, 0x33ad0000, 0x33ad0000)
   the space 10240K,   6% used [0x330d0000, 0x33175310, 0x33175400, 0x33ad0000)
compacting perm gen  total 12288K, used 371K [0x33ad0000, 0x346d0000, 0x37ad0000)
   the space 12288K,   3% used [0x33ad0000, 0x33b2cdf8, 0x33b2ce00, 0x346d0000)
    ro space 10240K,  54% used [0x37ad0000, 0x3804e770, 0x3804e800, 0x384d0000)
    rw space 12288K,  55% used [0x384d0000, 0x38b74ac8, 0x38b74c00, 0x390d0000)
是什么原因造成的,http://hllvm.group.iteye.com/group/wiki/2864-JVM,这个是之前群里面分析的垃圾回收过程,到我这里,实际情况怎么不一样了呢?
xm_king 2012-10-24
按照我的理解,在第二次YGC的时候,原来From区的0.5MB的bytes2对象和Eden区的bytes5对象都拷贝到To区,但是实际情况确实bytes2被放到了Old区,bytes5被放到了From区。群里的高人能解释一下是什么问题吗?
RednaxelaFX 2012-10-25
xm_king 写道
按照我的理解,在第二次YGC的时候,原来From区的0.5MB的bytes2对象和Eden区的bytes5对象都拷贝到To区,但是实际情况确实bytes2被放到了Old区,bytes5被放到了From区。群里的高人能解释一下是什么问题吗?

楼上的byte2是指byte3?

你打开-XX:+PrintTenuringDistribution大概就好理解了。当前生效的tenuring threshold会根据survivor space的使用量而调整,每次minor GC后都会重新计算一次。默认的TargetSurvivorRatio是50,也就是VM会试图调整当前有效的tenuring threshold希望下次minor GC后survivor的from区的使用量能接近50%。这个逻辑是在ageTable::compute_tenuring_threshold()里实现的,而DefNew/ParNew/G1都靠这个ageTable来统计和控制晋升行为,所以都受它影响。ParallelScavenge目前是不受这个参数控制的,请留意。

你会发现在你的第一个例子里,GC后因为survivor的使用量已经超过了50%所以VM决定把tenuring threshold降到1了;改成第二个例子的之后,第二次GC时原本在第一次GC后survivor里活着的对象都会晋升到old gen去。

就这样。

D:\experiment>\sdk\jdk1.6.0_26_32\bin\java -Xms20m -Xmx20m -Xmn10m -XX:+UseSerialGC -XX:SurvivorRatio=3 -XX:+PrintGCDetails -XX:+PrintTenuringDistribution GCDemo
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1723792 bytes,    1723792 total
: 3845K->1683K(8192K), 0.0099841 secs] 3845K->1683K(18432K), 0.0112439 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1048592 bytes,    1048592 total
: 5844K->1024K(8192K), 0.0070860 secs] 5844K->1683K(18432K), 0.0084690 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap
 def new generation   total 8192K, used 3318K [0x04530000, 0x04f30000, 0x04f30000)
  eden space 6144K,  37% used [0x04530000, 0x0476d7f8, 0x04b30000)
  from space 2048K,  50% used [0x04b30000, 0x04c30010, 0x04d30000)
  to   space 2048K,   0% used [0x04d30000, 0x04d30000, 0x04f30000)
 tenured generation   total 10240K, used 659K [0x04f30000, 0x05930000, 0x05930000)

   the space 10240K,   6% used [0x04f30000, 0x04fd4d80, 0x04fd4e00, 0x05930000)
 compacting perm gen  total 12288K, used 2099K [0x05930000, 0x06530000, 0x09930000)
   the space 12288K,  17% used [0x05930000, 0x05b3ce60, 0x05b3d000, 0x06530000)
No shared spaces configured.
xm_king 2012-10-25
确实是这样,在启动JVM的时候,加入-XX:TargetSurvivorRatio=90 ,可以基本保证JVM不会自动将tenuring threshold设置为1,这样在最后的时候,Old区中是没有对象的。非常感谢RednaxelaFX。我还有一个问题,from区和to区本质上是一样的,第一次GC后对象在S0区,S1区为空,S0区为From区,S1区为To区;第二次GC后对象都收集到了S1区,S0区为空,那么S1区就成了From区,S0区就成了To区。不知道我的理解是不是正确的。如果正确的话,那么从GC的log上来看是不是应该To区始终是空的呢?
RednaxelaFX 写道
xm_king 写道
按照我的理解,在第二次YGC的时候,原来From区的0.5MB的bytes2对象和Eden区的bytes5对象都拷贝到To区,但是实际情况确实bytes2被放到了Old区,bytes5被放到了From区。群里的高人能解释一下是什么问题吗?

楼上的byte2是指byte3?

你打开-XX:+PrintTenuringDistribution大概就好理解了。当前生效的tenuring threshold会根据survivor space的使用量而调整,每次minor GC后都会重新计算一次。默认的TargetSurvivorRatio是50,也就是VM会试图调整当前有效的tenuring threshold希望下次minor GC后survivor的from区的使用量能接近50%。这个逻辑是在ageTable::compute_tenuring_threshold()里实现的,而DefNew/ParNew/G1都靠这个ageTable来统计和控制晋升行为,所以都受它影响。ParallelScavenge目前是不受这个参数控制的,请留意。

你会发现在你的第一个例子里,GC后因为survivor的使用量已经超过了50%所以VM决定把tenuring threshold降到1了;改成第二个例子的之后,第二次GC时原本在第一次GC后survivor里活着的对象都会晋升到old gen去。

就这样。

D:\experiment>\sdk\jdk1.6.0_26_32\bin\java -Xms20m -Xmx20m -Xmn10m -XX:+UseSerialGC -XX:SurvivorRatio=3 -XX:+PrintGCDetails -XX:+PrintTenuringDistribution GCDemo
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1723792 bytes,    1723792 total
: 3845K->1683K(8192K), 0.0099841 secs] 3845K->1683K(18432K), 0.0112439 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1048592 bytes,    1048592 total
: 5844K->1024K(8192K), 0.0070860 secs] 5844K->1683K(18432K), 0.0084690 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap
 def new generation   total 8192K, used 3318K [0x04530000, 0x04f30000, 0x04f30000)
  eden space 6144K,  37% used [0x04530000, 0x0476d7f8, 0x04b30000)
  from space 2048K,  50% used [0x04b30000, 0x04c30010, 0x04d30000)
  to   space 2048K,   0% used [0x04d30000, 0x04d30000, 0x04f30000)
 tenured generation   total 10240K, used 659K [0x04f30000, 0x05930000, 0x05930000)

   the space 10240K,   6% used [0x04f30000, 0x04fd4d80, 0x04fd4e00, 0x05930000)
 compacting perm gen  total 12288K, used 2099K [0x05930000, 0x06530000, 0x09930000)
   the space 12288K,  17% used [0x05930000, 0x05b3ce60, 0x05b3d000, 0x06530000)
No shared spaces configured.
xiaoyu 2012-10-25
xm_king 写道
确实是这样,在启动JVM的时候,加入-XX:TargetSurvivorRatio=90 ,可以基本保证JVM不会自动将tenuring threshold设置为1,这样在最后的时候,Old区中是没有对象的。非常感谢RednaxelaFX。我还有一个问题,from区和to区本质上是一样的,第一次GC后对象在S0区,S1区为空,S0区为From区,S1区为To区;第二次GC后对象都收集到了S1区,S0区为空,那么S1区就成了From区,S0区就成了To区。不知道我的理解是不是正确的。如果正确的话,那么从GC的log上来看是不是应该To区始终是空的呢?
RednaxelaFX 写道
xm_king 写道
按照我的理解,在第二次YGC的时候,原来From区的0.5MB的bytes2对象和Eden区的bytes5对象都拷贝到To区,但是实际情况确实bytes2被放到了Old区,bytes5被放到了From区。群里的高人能解释一下是什么问题吗?

楼上的byte2是指byte3?

你打开-XX:+PrintTenuringDistribution大概就好理解了。当前生效的tenuring threshold会根据survivor space的使用量而调整,每次minor GC后都会重新计算一次。默认的TargetSurvivorRatio是50,也就是VM会试图调整当前有效的tenuring threshold希望下次minor GC后survivor的from区的使用量能接近50%。这个逻辑是在ageTable::compute_tenuring_threshold()里实现的,而DefNew/ParNew/G1都靠这个ageTable来统计和控制晋升行为,所以都受它影响。ParallelScavenge目前是不受这个参数控制的,请留意。

你会发现在你的第一个例子里,GC后因为survivor的使用量已经超过了50%所以VM决定把tenuring threshold降到1了;改成第二个例子的之后,第二次GC时原本在第一次GC后survivor里活着的对象都会晋升到old gen去。

就这样。

D:\experiment>\sdk\jdk1.6.0_26_32\bin\java -Xms20m -Xmx20m -Xmn10m -XX:+UseSerialGC -XX:SurvivorRatio=3 -XX:+PrintGCDetails -XX:+PrintTenuringDistribution GCDemo
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1723792 bytes,    1723792 total
: 3845K->1683K(8192K), 0.0099841 secs] 3845K->1683K(18432K), 0.0112439 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC [DefNew
Desired survivor size 1048576 bytes, new threshold 1 (max 15)
- age   1:    1048592 bytes,    1048592 total
: 5844K->1024K(8192K), 0.0070860 secs] 5844K->1683K(18432K), 0.0084690 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap
 def new generation   total 8192K, used 3318K [0x04530000, 0x04f30000, 0x04f30000)
  eden space 6144K,  37% used [0x04530000, 0x0476d7f8, 0x04b30000)
  from space 2048K,  50% used [0x04b30000, 0x04c30010, 0x04d30000)
  to   space 2048K,   0% used [0x04d30000, 0x04d30000, 0x04f30000)
 tenured generation   total 10240K, used 659K [0x04f30000, 0x05930000, 0x05930000)

   the space 10240K,   6% used [0x04f30000, 0x04fd4d80, 0x04fd4e00, 0x05930000)
 compacting perm gen  total 12288K, used 2099K [0x05930000, 0x06530000, 0x09930000)
   the space 12288K,  17% used [0x05930000, 0x05b3ce60, 0x05b3d000, 0x06530000)
No shared spaces configured.


其实每次ygc后, 一般情况下eden和to 都为空, 是的.

把 TargetSurvivorRatio 设置为90, 会有一点风险, 如果在某些特殊情况(突然创建了很多对象,或者大对象), 就会遇到s区溢出(放不下), 把本不应该移到old区的新对象, 移到old区

RednaxelaFX 2012-10-25
xm_king 写道
我还有一个问题,from区和to区本质上是一样的,第一次GC后对象在S0区,S1区为空,S0区为From区,S1区为To区;第二次GC后对象都收集到了S1区,S0区为空,那么S1区就成了From区,S0区就成了To区。不知道我的理解是不是正确的。如果正确的话,那么从GC的log上来看是不是应该To区始终是空的呢?

from和to在一般情况下会是一样大的,每次minor GC之后互换职责,“当前的to space”会是空的。

那VisualVM的Visual GC插件可以很形象的看到GC正常工作时各区的状况:

(这是我做的动画GIF,如果图被缩小了看起来没在动的话请单击查看原图)

但也有例外情况。如果在minor GC时old gen没有足够剩余空间容纳从young gen晋升上来的对象,就会发生promotion failure(晋升失败),然后minor GC会中止,转到full GC。然而如果full GC后仍然回收不到多少空间,此时如果GC决定“咬咬牙拼命了”,那就会让eden/from/to都继续放对象。已经到这个地步的时候多半离彻底不行也不远了所以不用太纠结这个时候到底是怎么处理的了。

xiaoyu 写道
其实每次ygc后, 一般情况下eden和to 都为空, 是的.

把 TargetSurvivorRatio 设置为90, 会有一点风险, 如果在某些特殊情况(突然创建了很多对象,或者大对象), 就会遇到s区溢出(放不下), 把本不应该移到old区的新对象, 移到old区

嗯,这就叫survivor space overflow。要尽量避免。默认的TargetSurvivorRatio设为50主要也是为了在一般情况下能有个缓冲,免得被突发的大量分配引致survivor space overflow。
Global site tag (gtag.js) - Google Analytics