关于CMS Full GC的奇怪现象

aronlulu 2012-03-08
这是虚拟机设置参数
 -Xms10240m -Xmx10240m -XX:PermSize=256m -XX:MaxPermSize=256m -XX:MaxDirectMemorySize=256m -XX:+UseBiasedLocking
-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:+PrintGCDetails -XX:+PrintGCApplicationStoppedTime  -Xloggc:./log/gc.log
-XX:ParallelCMSThreads=8 -Dfile.encoding=UTF-8

在观察gc日志的时候发现有很多full gc,最长的一次有6秒之长:
7471.630: [Full GC (System) 7471.631: [CMS: 1800106K->1426550K(10315392K), 6.5883540 secs] 1887677K->1426550K(10468736K), [CMS Perm : 111425K->108684K(262144K)] icms_dc=0 , 6.5890860 secs] [Times: user=6.59 sys=0.00, real=6.58 secs]
Total time for which application threads were stopped: 6.5915800 seconds
7478.222: [GC [1 CMS-initial-mark: 1426550K(10315392K)] 1426573K(10468736K), 0.0064870 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
Total time for which application threads were stopped: 0.0090620 seconds
7478.229: [CMS-concurrent-mark-start]
可是看回收时的空间利用率很低,远远没有达到触发full gc的条件,代码我也检查过了,没有调用system.gc的地方,程序是跑在24G内存的刀片机上的。
求高人分析一下。
RednaxelaFX 2012-03-08
你的代码没调用System.gc()不代表JDK的代码没有。
你的应用有没有使用NIO direct buffer或者RMI?有的话,JDK自己就会去调用System.gc()。
如果你用了别的一些库,像是JBoss容器之类的,它们里面也可能有System.gc()的调用。

你的机器多半不该使用iCMS。这个模式的应用场景请参考Oracle的GC开发写的一篇blog:Really? iCMS? Really?
也就是说不要打开-XX:+CMSIncrementalMode
aronlulu 2012-03-08
感谢撒加的回答,我关掉试试,另外还想请教一个问题,有没有办法定位我引用的jar包是不是调用了system.gc呢,对于这种full gc有没有日志能大致看出什么地方调用的?
RednaxelaFX 2012-03-08
aronlulu 写道
对于这种full gc有没有日志能大致看出什么地方调用的?

可以用BTrace试试。写个类似这样的BTrace脚本直接挂在你的Java进程的启动参数里:
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
public class TraceSystemGCCall {
  @OnMethod(
    clazz="/.*/",
    method="/.*/",
    location=@Location(
      value=Kind.CALL,
      clazz="java.lang.System",
      method="gc"
    )
  )
  public static void onSystemGC() {
    jstack();
  }
}

具体挂载的用法之类请参考官方文档:http://kenai.com/projects/btrace/pages/UserGuide
aronlulu 2012-03-09
RednaxelaFX 写道
aronlulu 写道
对于这种full gc有没有日志能大致看出什么地方调用的?

可以用BTrace试试。写个类似这样的BTrace脚本直接挂在你的Java进程的启动参数里:
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
public class TraceSystemGCCall {
  @OnMethod(
    clazz="/.*/",
    method="/.*/",
    location=@Location(
      value=Kind.CALL,
      clazz="java.lang.System",
      method="gc"
    )
  )
  public static void onSystemGC() {
    jstack();
  }
}

具体挂载的用法之类请参考官方文档:http://kenai.com/projects/btrace/pages/UserGuide

很好使的工具,感谢撒迦。
lmdxr 2012-05-07

你的gc日志可以看出肯定存在System.gc或Runtime.getRuntime().gc的调用,因为gc日志有关键词“(System)”,建议你检查一下你的代码以及第三方组件。
 详细分析过程见我的boke:
http://lmdxr.iteye.com/blog/1513345

Global site tag (gtag.js) - Google Analytics