[讨论] [HotSpot VM] JVM调优的"标准参数"的各种陷阱
 |
RednaxelaFX
2011-11-08
hittyt 写道 本人的java环境如下：
java -version java version "1.6.0_18" Java(TM) SE Runtime Environment (build 1.6.0_18-b07) Java HotSpot(TM) 64-Bit Server VM (build 16.0-b13, mixed mode) 但使用PrintFlagsFinal时得到的输出却是下面的结果： java -XX:+PrintFlagsFinal Unrecognized VM option '+PrintFlagsFinal' Could not create the Java virtual machine. 求LZ解答问题在哪里呢？ 我在顶楼的帖里明明写了… RednaxelaFX 写道 接着是 -XX:+PrintFlagsFinal 。前一个参数只显示跟默认值不同的，而这个参数则可以显示所有可设置的参数及它们的值。不过这个参数本身只从JDK 6 update 21开始才可以用，之前的Oracle/Sun JDK则用不了。
而且还标红了…诶。 |
 |
hittyt
2011-11-09
So sorry
 Anyway, thanks for your replying again.
|
 |
hoorace
2011-11-15
在使用CMS GC时，添加-XX:+UseNUMA参数后，导致CPU使用率居高不下。
具体参数是： -XX:+UseConcMarkSweepGC -XX:ParallelCMSThreads=4 -XX:+UseNUMA |
|
RednaxelaFX
2011-11-15
hoorace 写道 在使用CMS GC时，添加-XX:+UseNUMA参数后，导致CPU使用率居高不下。
具体参数是： -XX:+UseConcMarkSweepGC -XX:ParallelCMSThreads=4 -XX:+UseNUMA 请问具体是在什么样的机器上，哪个版本的JDK上跑遇到了这样的情况呢？ |
 |
zhangyou1010
2011-11-20
晕，在chrome16下面，看不到楼主的Command line 中的代码，在ie8下可以看到。
|
|
RednaxelaFX
2011-11-20
zhangyou1010 写道 晕，在chrome16下面，看不到楼主的Command line 中的代码，在ie8下可以看到。
我在用的是Chrome 15，没看到有啥问题。如果显示不出来请截图到站务那边反映一下～ |
 |
ningandjin
2012-01-29
R大，1、-XX:+DisableExplicitGC 与 NIO的direct memory 里面的那个例子下面的这句话“例子里用-XX:MaxDirectMemorySize=10m限制了DirectByteBuffer能分配的空间的限额，以便问题更容易展现出来。不用这个参数就得多跑一会儿了。 ”是不是有点问题啊？如果不设置-XX:MaxDirectMemorySize=10m，是不会跑出OOM的，因为你后面说“死在young gen中的DirectByteBuffer对象会在young GC时被处理”。所以分配的DirectByteBuffer会在minorGC的时候回收掉吧。我猜测加上-XX:MaxDirectMemorySize=10m 抛出OOM的原因是触发minorGC前就到了DirectMemory的限制，但是我把参数“-XX:+PrintGCDetails -XX:+DisableExplicitGC -XX:MaxDirectMemorySize=10m”加上，
运行结果如下： [GC [DefNew: 4416K->511K(4928K), 0.0114065 secs] 4416K->4327K(15872K), 0.0114548 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] [GC [DefNew: 4927K->511K(4928K), 0.0188013 secs] 8743K->8741K(15872K), 0.0188398 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] Exception in thread "main" java.lang.OutOfMemoryError: Direct buffer memory at java.nio.Bits.reserveMemory(Bits.java:633) at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:98) at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:288) at jvm.NativeMemoryGC.main(NativeMemoryGC.java:34) 是怎么回事呢？ |
|
RednaxelaFX
2012-01-30
ningandjin 写道 R大，1、-XX:+DisableExplicitGC 与 NIO的direct memory 里面的那个例子下面的这句话“例子里用-XX:MaxDirectMemorySize=10m限制了DirectByteBuffer能分配的空间的限额，以便问题更容易展现出来。不用这个参数就得多跑一会儿了。 ”是不是有点问题啊？ 在我给的例子里这句话是没问题的。条件限定。 顺带提醒后面的人看，后面第5条也提到了NIO direct memory分配上限的默认值问题。 ningandjin 写道 如果不设置-XX:MaxDirectMemorySize=10m，是不会跑出OOM的，因为你后面说“死在young gen中的DirectByteBuffer对象会在young GC时被处理”。 问题是有没有触发young GC，什么时候触发的，那个时候你关心的DirectByteBuffer死了没。这个时候你必须要把你跑的测试的具体代码完整贴出来。你的代码和测试条件如果跟我举的例子不一样的话，讨论的是不是同一个东西就难说了。 ningandjin 写道 [GC [DefNew: 4416K->511K(4928K), 0.0114065 secs] 4416K->4327K(15872K), 0.0114548 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] [GC [DefNew: 4927K->511K(4928K), 0.0188013 secs] 8743K->8741K(15872K), 0.0188398 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 这里你是不是感到很困惑？很明显要么你的测试环境跟我的不一样，要么你的测试代码跟我的不一样，因为我的测试里是一次GC都没有出现过的，无论是young GC还是full GC。 请先把完整代码和测试环境信息贴出来。 另外，也可以加上-XX:+PrintReferenceGC -XX:+PrintGCDetails来得到更多信息，这样能观察到到底你的测试里每次GC处理了多少个、什么类型的弱引用。Cleaner-based的清理是基于PhantomReference的。 |
|
ningandjin
2012-01-30
OS：Windows 7 professional ，内存2G
JDK版本：java version "1.6.0_21" Java(TM) SE Runtime Environment (build 1.6.0_21-b07) Java HotSpot(TM) Client VM (build 17.0-b17, mixed mode, sharing) 代码: public class NativeMemoryGC
{
public static void main(String[] args)
throws SecurityException, NoSuchFieldException, ClassNotFoundException, IllegalArgumentException,
IllegalAccessException, InterruptedException
{
for (int i = 0; i < 100000; i++)
{
ByteBuffer.allocateDirect(128);
}
System.out.println("Done");
}
}
运行参数：-XX:+PrintReferenceGC -XX:+DisableExplicitGC -XX:+PrintGCDetails -XX:MaxDirectMemorySize=10m 运行结果： [GC [DefNew[SoftReference, 0 refs, 0.0000081 secs][WeakReference, 1 refs, 0.0000056 secs][FinalReference, 2 refs, 0.0000075 secs][PhantomReference, 5779 refs, 0.0008828 secs][JNI Weak Reference, 0.0000036 secs]: 4416K->511K(4928K), 0.0113104 secs] 4416K->4327K(15872K), 0.0113425 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC [DefNew[SoftReference, 0 refs, 0.0000084 secs][WeakReference, 0 refs, 0.0000053 secs][FinalReference, 0 refs, 0.0000045 secs][PhantomReference, 8193 refs, 0.0018153 secs][JNI Weak Reference, 0.0000036 secs]: 4927K->511K(4928K), 0.0152790 secs] 8743K->8741K(15872K), 0.0153095 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Direct buffer memory
at java.nio.Bits.reserveMemory(Bits.java:633)
at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:98)
at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:288)
at jvm.NativeMemoryGC.main(NativeMemoryGC.java:34)
Heap
def new generation total 4928K, used 3314K [0x24040000, 0x24590000, 0x29590000)
eden space 4416K, 63% used [0x24040000, 0x242fc848, 0x24490000)
from space 512K, 99% used [0x24490000, 0x2450fff8, 0x24510000)
to space 512K, 0% used [0x24510000, 0x24510000, 0x24590000)
tenured generation total 10944K, used 8229K [0x29590000, 0x2a040000, 0x34040000)
the space 10944K, 75% used [0x29590000, 0x29d99718, 0x29d99800, 0x2a040000)
compacting perm gen total 12288K, used 373K [0x34040000, 0x34c40000, 0x38040000)
the space 12288K, 3% used [0x34040000, 0x3409d760, 0x3409d800, 0x34c40000)
ro space 10240K, 54% used [0x38040000, 0x385bc0f0, 0x385bc200, 0x38a40000)
rw space 12288K, 55% used [0x38a40000, 0x390dfb80, 0x390dfc00, 0x39640000)
|
|
RednaxelaFX
2012-01-30
嗯，找了台32位Windows XP的机器，能再现出你看到的现象。
把你的实验稍微改了一下，把相关代码和实验输出放在这里了：https://gist.github.com/1704102#file_command_prompt 这个版本里，我修改了DirectByteBuffer的代码，让它： * 整个类变为public的，方便访问里面的状态； * 在构造器里记录下到底创建了多少个DirectByteBuffer对象（并检查传入的大小是否为128，仅为实验用）； * 同时在相应的Deallocator里记录有多少个DirectByteBuffer得到了释放（也就是其Cleaner得到了执行）。 实验用的DirectByteBuffer.java是从JDK7的rt.jar反编译出来的。懒得从源码包的Direct-X-Buffer.java慢慢改…那个gist里的DirectByteBuffer.java源码里行首没有/* */的行就是新加的代码。 然后在NativeMemoryGC这个实验类里，借助JDK7的GC Notification功能，在每次GC过后打印10次当前DirectByteBuffer的分配/释放状况，每隔10ms打印一次。 Cleaner的执行是在Reference Handler线程上执行，而GC Notification是在Service Thread上处理的（请参考另一个gist），两者都与NativeMemoryGC.main()所在的Main线程是并发的，所以多打印几次DirectByteBuffer统计信息能看到Cleaner是一个个执行过去的，不是在GC后瞬间就执行完的，与此同时main()里的实验代码还在不断调用ByteBuffer.allocateDirect(128)创建新的DirectByteBuffer对象。 最终能看到deallocated的数量跟GC日志里显示的得到处理的PhantomReference数量一致。 =============================================================== 但是为什么只有部分DirectByteBuffer被释放？ 实验程序里没有显式引用ByteBuffer.allocateDirect(128)所返回的DirectByteBuffer对象，那么在young GC的时候这些对象都应该死掉。是么？ 可惜不是。 事实上，因为在32位Windows/2G内存/HotSpot Client VM这种组合的默认配置下，Java heap的初始大小和最大大小都比较小，实验中有很多DirectByteBuffer和相应的sun.misc.Cleaner、DirectByteBuffer$Deallocator对象都没死在young gen里，而是在young GC后仍然存活，一些在survivor space之间捣腾，另一些因为survivor space发生了溢出而直接晋升到old gen去了。这可以从jstat的输出中有survivor space的使用量达到100%得知。 与WeakReference相比，PhantomReference的一个特点是后者不会阻止它所引用的对象（referent）被GC所回收。 sun.misc.Cleaner是基于PhantomReference的，也就是说它本身不会阻碍它所引用的DirectByteBuffer对象在GC时被回收。 实际问题出在GC做weak reference discovery的逻辑上。如果背景知识感觉还不够清晰的话，请先读一下Xiao-Feng Li以前写的两篇blog： http://xiao-feng.blogspot.com/2007/05/weak-reference-in-jvm.html http://xiao-feng.blogspot.com/2007/05/weak-reference-processing-in-apache.html 其中第二篇是针对Apache Harmony和里面的DRLVM描述的。HotSpot VM的ReferenceProcessor跟这个在大体概念上很相似，有现成的描述我就懒得码字了。 HotSpot VM的weak reference discovery是在ReferenceProcessor::discover_reference(oop obj, ReferenceType rt)这里实现的。其中有个参数，RefDiscoveryPolicy，有两个可选值，其中0是默认： // We mention two of several possible choices here: // #0: if the reference object is not in the "originating generation" // (or part of the heap being collected, indicated by our "span" // we don't treat it specially (i.e. we scan it as we would // a normal oop, treating its references as strong references). // This means that references can't be enqueued unless their // referent is also in the same span. This is the simplest, // most "local" and most conservative approach, albeit one // that may cause weak references to be enqueued least promptly. // We call this choice the "ReferenceBasedDiscovery" policy. // #1: the reference object may be in any generation (span), but if // the referent is in the generation (span) being currently collected // then we can discover the reference object, provided // the object has not already been discovered by // a different concurrently running collector (as may be the // case, for instance, if the reference object is in CMS and // the referent in DefNewGeneration), and provided the processing // of this reference object by the current collector will // appear atomic to every other collector in the system. // (Thus, for instance, a concurrent collector may not // discover references in other generations even if the // referent is in its own generation). This policy may, // in certain cases, enqueue references somewhat sooner than // might Policy #0 above, but at marginally increased cost // and complexity in processing these references. // We call this choice the "RefeferentBasedDiscovery" policy. 默认的弱引用发现策略非常保守，不幸在这个实验里就踩到雷——有些sun.misc.Cleaner会错过“被发现”的条件，具体正是因为它们被直接晋升到old gen了。我做了另外一个实验，在VM里打了些日志，从而确认到这点：https://gist.github.com/1709569 同一个实验只要设置-XX:RefDiscoveryPolicy=1就没问题了。 实验日志：https://gist.github.com/1704102#file_command_prompt2 之所以默认不用这个策略是因为这个策略一般会稍微慢一些。但在出问题的时候，稍微慢一些总比OOM好… 或者，其实只要不让survivor space overflow发生就好了，这样在这个实验里就不会有在young GC中被漏扫的弱引用。 如何能保证这个实验里survivor space不会overflow？很简单，让survivor space不小于eden就行。也就是说用-XX:SurvivorRatio=1同样能避开这个例子里的OOME： D:\>\sdk\jdk7\bin\java -XX:+PrintReferenceGC -XX:+DisableExplicitGC -XX:+PrintGCDetails -XX:MaxDirectMemorySize=10m -Xbootclasspath/p:altclasses -XX:SurvivorRatio=1 NativeMemoryGC [GC [DefNew[SoftReference, 0 refs, 0.0000159 secs][WeakReference, 62 refs, 0.0000208 secs][FinalReference, 5 refs, 0.0000199 secs][PhantomReference, 5455 refs,0.0005686 secs][JNI Weak Reference, 0.0047739 secs]: 1856K->1358K(3648K), 0.0492946 secs] 1856K->1358K(14592K), 0.0493708 secs] [Times: user=0.00 sys=0.00, real=0.05 secs] GC #1 DirectByteBuffer: allocated = 5528, deallocated = 5455 DirectByteBuffer: allocated = 5779, deallocated = 5455 DirectByteBuffer: allocated = 5784, deallocated = 5455 DirectByteBuffer: allocated = 5790, deallocated = 5455 DirectByteBuffer: allocated = 5795, deallocated = 5455 DirectByteBuffer: allocated = 5800, deallocated = 5455 DirectByteBuffer: allocated = 5806, deallocated = 5455 DirectByteBuffer: allocated = 5812, deallocated = 5455 DirectByteBuffer: allocated = 5817, deallocated = 5455 DirectByteBuffer: allocated = 5822, deallocated = 5455 [GC [DefNew[SoftReference, 0 refs, 0.0000531 secs][WeakReference, 1 refs, 0.0000120 secs][FinalReference, 9 refs, 0.0000463 secs][PhantomReference, 11395 refs,0.0012726 secs][JNI Weak Reference, 0.0000023 secs]: 3214K->1561K(3648K), 0.0076529 secs] 3214K->2237K(14592K), 0.0082608 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] GC #2 DirectByteBuffer: allocated = 16850, deallocated = 6557 DirectByteBuffer: allocated = 16856, deallocated = 16850 DirectByteBuffer: allocated = 16861, deallocated = 16850 DirectByteBuffer: allocated = 16867, deallocated = 16850 DirectByteBuffer: allocated = 16873, deallocated = 16850 DirectByteBuffer: allocated = 16878, deallocated = 16850 DirectByteBuffer: allocated = 16884, deallocated = 16850 DirectByteBuffer: allocated = 16889, deallocated = 16850 DirectByteBuffer: allocated = 16895, deallocated = 16850 DirectByteBuffer: allocated = 16900, deallocated = 16850 [GC [DefNew[SoftReference, 0 refs, 0.0000179 secs][WeakReference, 0 refs, 0.0000105 secs][FinalReference, 0 refs, 0.0000102 secs][PhantomReference, 14473 refs,0.0014199 secs][JNI Weak Reference, 0.0000014 secs]: 3417K->1791K(3648K), 0.0055595 secs] 4093K->2622K(14592K), 0.0056227 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] GC #3 DirectByteBuffer: allocated = 31323, deallocated = 19558 DirectByteBuffer: allocated = 31330, deallocated = 31323 DirectByteBuffer: allocated = 31335, deallocated = 31323 DirectByteBuffer: allocated = 31340, deallocated = 31323 DirectByteBuffer: allocated = 31346, deallocated = 31323 DirectByteBuffer: allocated = 31351, deallocated = 31323 DirectByteBuffer: allocated = 31357, deallocated = 31323 DirectByteBuffer: allocated = 31362, deallocated = 31323 DirectByteBuffer: allocated = 31368, deallocated = 31323 DirectByteBuffer: allocated = 31373, deallocated = 31323 [GC [DefNew[SoftReference, 0 refs, 0.0000155 secs][WeakReference, 0 refs, 0.0000104 secs][FinalReference, 0 refs, 0.0000103 secs][PhantomReference, 14492 refs,0.0013976 secs][JNI Weak Reference, 0.0000012 secs]: 3647K->1791K(3648K), 0.0042904 secs] 4478K->2669K(14592K), 0.0043564 secs] [Times: user=0.00 sys=0.02, real=0.02 secs] GC #4 DirectByteBuffer: allocated = 45816, deallocated = 32990 DirectByteBuffer: allocated = 45822, deallocated = 45815 DirectByteBuffer: allocated = 45828, deallocated = 45815 DirectByteBuffer: allocated = 45833, deallocated = 45815 DirectByteBuffer: allocated = 45838, deallocated = 45815 DirectByteBuffer: allocated = 45844, deallocated = 45815 DirectByteBuffer: allocated = 45850, deallocated = 45815 DirectByteBuffer: allocated = 45855, deallocated = 45815 DirectByteBuffer: allocated = 45861, deallocated = 45815 DirectByteBuffer: allocated = 45866, deallocated = 45815 [GC [DefNew[SoftReference, 0 refs, 0.0000484 secs][WeakReference, 0 refs, 0.0000389 secs][FinalReference, 0 refs, 0.0000424 secs][PhantomReference, 14606 refs,0.0016005 secs][JNI Weak Reference, 0.0000019 secs]: 3647K->1791K(3648K), 0.0050811 secs] 4525K->2736K(14592K), 0.0052789 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] GC #5 DirectByteBuffer: allocated = 60422, deallocated = 46609 DirectByteBuffer: allocated = 60427, deallocated = 60421 DirectByteBuffer: allocated = 60433, deallocated = 60421 DirectByteBuffer: allocated = 60438, deallocated = 60421 DirectByteBuffer: allocated = 60443, deallocated = 60421 DirectByteBuffer: allocated = 60449, deallocated = 60421 DirectByteBuffer: allocated = 60454, deallocated = 60421 DirectByteBuffer: allocated = 60460, deallocated = 60421 DirectByteBuffer: allocated = 60466, deallocated = 60421 DirectByteBuffer: allocated = 60470, deallocated = 60421 [GC [DefNew[SoftReference, 0 refs, 0.0000155 secs][WeakReference, 0 refs, 0.0000104 secs][FinalReference, 0 refs, 0.0000103 secs][PhantomReference, 14572 refs,0.0012682 secs][JNI Weak Reference, 0.0000014 secs]: 3647K->1791K(3648K), 0.0037896 secs] 4592K->2813K(14592K), 0.0038488 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] GC #6 DirectByteBuffer: allocated = 74994, deallocated = 62238 DirectByteBuffer: allocated = 74999, deallocated = 74993 DirectByteBuffer: allocated = 75005, deallocated = 74993 DirectByteBuffer: allocated = 75011, deallocated = 74993 DirectByteBuffer: allocated = 75016, deallocated = 74993 DirectByteBuffer: allocated = 75022, deallocated = 74993 DirectByteBuffer: allocated = 75027, deallocated = 74993 DirectByteBuffer: allocated = 75032, deallocated = 74993 DirectByteBuffer: allocated = 75038, deallocated = 74993 DirectByteBuffer: allocated = 75043, deallocated = 74993 [GC [DefNew[SoftReference, 0 refs, 0.0000178 secs][WeakReference, 0 refs, 0.0000123 secs][FinalReference, 0 refs, 0.0000109 secs][PhantomReference, 14577 refs,0.0015853 secs][JNI Weak Reference, 0.0000015 secs]: 3647K->1792K(3648K), 0.0043279 secs] 4669K->2885K(14592K), 0.0043876 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] GC #7 DirectByteBuffer: allocated = 89571, deallocated = 76182 DirectByteBuffer: allocated = 89576, deallocated = 89570 DirectByteBuffer: allocated = 89581, deallocated = 89570 DirectByteBuffer: allocated = 89587, deallocated = 89570 DirectByteBuffer: allocated = 89592, deallocated = 89570 DirectByteBuffer: allocated = 89598, deallocated = 89570 DirectByteBuffer: allocated = 89604, deallocated = 89570 DirectByteBuffer: allocated = 89609, deallocated = 89570 DirectByteBuffer: allocated = 89615, deallocated = 89570 DirectByteBuffer: allocated = 89620, deallocated = 89570 Done Heap def new generation total 3648K, used 3172K [0x02a60000, 0x02fb0000, 0x07fb0000) eden space 1856K, 74% used [0x02a60000, 0x02bb9230, 0x02c30000) from space 1792K, 100% used [0x02df0000, 0x02fb0000, 0x02fb0000) to space 1792K, 0% used [0x02c30000, 0x02c30000, 0x02df0000) tenured generation total 10944K, used 1093K [0x07fb0000, 0x08a60000, 0x12a60000) the space 10944K, 9% used [0x07fb0000, 0x080c1668, 0x080c1800, 0x08a60000) compacting perm gen total 12288K, used 3268K [0x12a60000, 0x13660000, 0x16a60000) the space 12288K, 26% used [0x12a60000, 0x12d913f0, 0x12d91400, 0x13660000) No shared spaces configured. D:\> 不得不说这些VM参数弄多了就像黑魔法一样…咒语知道多了整个人都黑了 
=============================================================== 相关的一些额外实验记录在这里：https://gist.github.com/1709717 可以看到HotSpot VM的DefNewGeneration是如何一边扫描活对象，一边把途中遇到的活的弱引用做一定过滤后记录下来（这就是weak reference discovery），活对象都扫完之后做(weak) reference processing，找出referent已经死掉的弱引用加到相应的链表里，然后通知Java一侧的Reference Handler进行后续的处理（执行cleaner，或把弱引用添加到相应的ReferenceQueue之类）。 顺带一提，JDK6的HotSpot VM里Java类在VM里的表示几乎都是用instanceKlass；唯有的例外是各弱引用类型，它们的类用instanceRefKlass表示。 JDK7的HotSpot VM则新增了一种例外：java.lang.Class类型本身，在VM里的表示从以前用instanceKlass改为用一种新增的instanceMirrorKlass。这是PermGen移除工作的一部分实现，由于原本放在instanceKlass末尾的“Java类静态变量”现在挪到了java.lang.Class实例的末尾，使得这些对象变成了特殊对象，所以对应的klass也要特殊处理了。 << 这段话没看懂的同学请直接无视…看不懂没关系嗯 
|
