昨天中午的时候, 团队的兄弟找我看一个现象: 原先因为堆外内存使用过多会crash掉的java应用, 设置了最大堆外内存量(MaxDirectMemorySize)后jvm不会crash, 但出现了机器的两颗CPU全部被占满, 而且java程序没有响应的情况.
我用jstat -gc/-gcutil/-gccause查了一下当时gc的情况, 发现出现过CMS GC, 最后一次导致GC的原因是CMS final remark, 没有什么异常. 新生代和旧生代占用量都比较少, survior的from与to区域都正常. 这就比较诡异了, 如果因为堆外内存超出了MaxDirectMemorySize设置的值, 那会抛出OOM, 但这个没有抛出.
检查了DisableExplicitGC参数,是否关闭了显式GC, 结果没有关闭. 这就更说不通了.
于是我转向调查CPU使用率为什么这么高. 用top查了一下CPU有几个jvm的线程(top运行后, 用shift + h开启线程观察)占着CPU, 线程的ID分别是: 38024, 38025, 38026, 38027.
然后采用pstack查看这几个线程究竟在干什么. pstack了好几次, 每次这些线程的stack都差不多, 如下:
#0 0x00007f1444751b60 in SpinPause@plt () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#1 0x00007f14447fbf09 in ParallelTaskTerminator::offer_termination() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#2 0x00007f1444c7fa87 in CMSRefProcTaskProxy::do_work_steal(int, CMSParDrainMarkingStackClosure*, CMSParKeepAliveClosure*, int*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#3 0x00007f1444c776e5 in CMSRefProcTaskProxy::work(int) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#4 0x00007f1444b40e2a in GangWorker::loop() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#5 0x00007f1444af8e98 in GangWorker::run() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#6 0x00007f1444af8278 in java_start(Thread*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#7 0x000000375560677d in start_thread () from /lib64/libpthread.so.0
#8 0x0000003754ed49ad in clone () from /lib64/libc.so.6
Thread 219 (Thread 0x40708940 (LWP 38025)):
#0 0x0000003754ebb5a7 in sched_yield () from /lib64/libc.so.6
#1 0x00007f1444a267e9 in ParallelTaskTerminator::yield() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#2 0x00007f14447fbfc9 in ParallelTaskTerminator::offer_termination() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#3 0x00007f1444c7fa87 in CMSRefProcTaskProxy::do_work_steal(int, CMSParDrainMarkingStackClosure*, CMSParKeepAliveClosure*, int*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#4 0x00007f1444c776e5 in CMSRefProcTaskProxy::work(int) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#5 0x00007f1444b40e2a in GangWorker::loop() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#6 0x00007f1444af8e98 in GangWorker::run() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#7 0x00007f1444af8278 in java_start(Thread*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#8 0x000000375560677d in start_thread () from /lib64/libpthread.so.0
#9 0x0000003754ed49ad in clone () from /lib64/libc.so.6
Thread 218 (Thread 0x40a3c940 (LWP 38026)):
#0 0x00007f1444751b60 in SpinPause@plt () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#1 0x00007f14447fbf09 in ParallelTaskTerminator::offer_termination() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#2 0x00007f1444c7fa87 in CMSRefProcTaskProxy::do_work_steal(int, CMSParDrainMarkingStackClosure*, CMSParKeepAliveClosure*, int*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#3 0x00007f1444c776e5 in CMSRefProcTaskProxy::work(int)() from /opt/taobao/install
/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#4 0x00007f1444b40e2a in GangWorker::loop() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#5 0x00007f1444af8e98 in GangWorker::run() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#6 0x00007f1444af8278 in java_start(Thread*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#7 0x000000375560677d in start_thread () from /lib64/libpthread.so.0
#8 0x0000003754ed49ad in clone () from /lib64/libc.so.6
Thread 217 (Thread 0x40277940 (LWP 38027)):
#0 0x00007f1444871b29 in SpinPause () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#1 0x00007f14447fbf09 in ParallelTaskTerminator::offer_termination() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#2 0x00007f1444c7fa87 in CMSRefProcTaskProxy::do_work_steal(int, CMSParDrainMarkingStackClosure*, CMSParKeepAliveClosure*, int*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#3 0x00007f1444c776e5 in CMSRefProcTaskProxy::work(int) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#4 0x00007f1444b40e2a in GangWorker::loop() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#5 0x00007f1444af8e98 in GangWorker::run() () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#6 0x00007f1444af8278 in java_start(Thread*) () from /opt/taobao/install/jdk-1.6.0_26/jre/lib/amd64/server/libjvm.so
#7 0x000000375560677d in start_thread () from /lib64/libpthread.so.0
#8 0x0000003754ed49ad in clone () from /lib64/libc.so.6
一眼就可以看出这些都是CMS GC的线程. 他们都停留在CMSRefProcTaskProxy::work下, GC的stack看上去还正常.奇怪的是为什么这么占CPU, 看样子一直在自旋(spin)或yield, 貌似在等待啥状态完成. 自旋锁是占CPU的利器.
要了一份gc log后, 看看gc log是否有啥线索. 发现一个非常诡异的地方:
2012-10-30T11:44:56.808+0800: 2603.044: [CMS-concurrent-preclean-start]
2012-10-30T11:44:56.811+0800: 2603.047: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2012-10-30T11:44:56.811+0800: 2603.047: [GC[YG occupancy: 13211 K (917504 K)]2603.047: [Rescan (parallel) , 0.0113650 secs]2603.059: [weak refs processing
GC log没有remark, 更没有sweep阶段, 停留在了weak refs processing. 这一阶段正在回收弱引用, 属于remark阶段的一部分, 所以会暂停java应用(stop the world)的. 日志与pstack正好吻合, 正在做处理引用 (CMSRefProcTaskProxy).但处理引用, 为什么会使jvm hang住, 并且不停地自旋等待某状态完成呢?
我用google查了一下, OTN上有两个人碰到了相同的问题: 链接一 链接二
从上面的两个链接上看, 没有人能解释这个现象. 但有一个线索, 可以解决这个问题:
把ParallelRefProcEnabled参数给关闭就可以解决这个问题. 这是并行处理引用的参数,可以使用多GC线程处理引用. 我用
- java -XX:+PrintFlagsFinal | grep ParallelRefProcEnabled
java -XX:+PrintFlagsFinal | grep ParallelRefProcEnabled
查看了一下, 它的默认值是false, 也就是默认关闭了. 向应用方要了一份JVM参数后发现, 线上这个参数是开着的.
开启这个参数为什么会使CMSRefProcTaskProxy一直在自旋, 从而停止Java应用, 并用占用所有的CPU资源呢? 再次请教google大神, 用”ParallelRefProcEnabled hang”发现了这个jvm的bug, 上面写着
reference processing线程个数与ParallelGCThreads参数来一样, 刚好此应用将ParallelGCThreads设为了4, 所以对应了pstack看到4个线程在处理引用的情况. 再次咨询了JVM团队,理解那句话的意思. 以上的terminator object是用来同步和管理gc线程的对象. 它会记录到目前为止已经完成的线程数_complete_threads , 当一个gc线程干完活后,他会把数_complete_threads+1,当terminator object确定已经完成的线程数_complete_threads==预先设置的所有的gc线程数_n_thread,所有的gc线程就会退出,否则其他的gc线程就会等待. 悲剧的是_n_thread在构造时为0, 后面一直没有被重设过. 所以只需要开启ParallelRefProcEnabled就会出问题. 现在能解释通了, 并且从刚才的pstack我们还可以发现停留在ParallelTaskTerminator::offer_termination()方法, 是这表示当前的gc线程没事干, 一直等待GC Terminator通知它结束, 所以它一直处于自旋锁的状态, 所以CPU才会这么高.
简单地关闭掉了ParallelRefProcEnabled之后, 以上这个现象就不会出现了. 这个bug在JDK7中已经解决, 根据应用团队的反馈, 线上此应用的机器有部分是JDK6u26,还有JDK6u30都出现过相同的现象. 官方说明JDK6u32已经fix掉这个bug, patch中显示_n_thread已经被正确地设为ygc的线程数,所以直到6u32的版本才能放心使用这个参数.
相关推荐
jvm 配置jvm参数 配置jvm参数
JVM参数使用说明
JVM参数设置,提供java虚拟机运行时的参数设置
如何配置jvm参数,并且调优,适合各路开发者,
常用jvm参数都在这张图中,参考起来方便,是国外大神整理的
IBM JVM参数选项 虚拟机参数
(中英文)JVM 参数详解,用心整理成Excel文档。包含所有近100条JVM参数的详细说明及设置方法,中英文对照,极方便阅读。转载请标明我这的源地址:http://download.csdn.net/download/xiucaiyao/10257573
JVM参数调优 及 JAVA相关工具使用
java启动参数共分为三类; 其一是标准参数(-),所有的...其三是非Stable参数(-XX),此类参数各个jvm实现会有所不同,将来可能会随时取消,需要慎重使用; 本文主要描述标准参数部分,剩下的两个部分将会陆续推出
常用的JVM参数,适合于线上关键业务系统,通用参数设置经验
jvm 参数调优实践,有代码可供参考,详细调优比较!
1、JVM参数推荐 2、Java运行时数据区 3、JVM内存模型 4、堆的内存划分 5、垃圾回收(GC) 6、JVM参数汇总
linux 下jvm基本参数设置 查看linux jvm的设置基本命令
在/usr/local/apache-tomcat-5.5.23/bin目录下的catalina.sh 添加:JAVA_OPTS='-Xms512m -Xmx1024m' 要加“m”说明是MB,否则就是KB了,在启动tomcat时会报内存不足。 -Xms:初始值 -Xmx:最大值 ...
JVM优化3(Tomcat参数调优,JVM参数调优,jvm字节码,代码优化),供大家查阅!!!!!!!!!!!!!!
详述tomcat服务端配置,使并发更加流畅
深入详解JVM内存模型与JVM参数详细配置,感兴趣的小伙伴们可以一块学习下。
jvm参数优化后,tomcat稳定可靠,附件为通过长时间在线测试的配置参数文件
可通过设置jvm参数,提高系统性能。内含一些系统原理。
jvm配置参数详解,以及Java gc详解