CrashReport系统在游戏内测当天出现了异常情况JVM僵死,通过top -p
----------------- 18540 -----------------
0xb7904280 _ZN9MarkSweep12follow_stackEv + 0x30
0xb79b0637 _ZN11PSMarkSweep17mark_sweep_phase1Eb + 0xe7
0xb79af737 _ZN11PSMarkSweep16invoke_no_policyEb + 0x3c7
0xb79ba0ae _ZN10PSScavenge6invokeEv + 0x12e
0xb797f999 _ZN20ParallelScavengeHeap19failed_mem_allocateEjb + 0x49
0xb7ab191a _ZN29VM_ParallelGCFailedAllocation4doitEv + 0x5a
0xb7ac0096 _ZN12VM_Operation8evaluateEv + 0x46
0xb7abf523 _ZN8VMThread18evaluate_operationEP12VM_Operation + 0x83
0xb7abf794 _ZN8VMThread4loopEv + 0x194
0xb7abf280 _ZN8VMThread3runEv + 0x80
0xb796d64e _Z10java_startP6Thread + 0x14e
0x0056849b start_thread + 0xcb
Parallel GC 是JVM的垃圾回收线程( ParallelGC垃圾回收方式的特点是在New区开启多线程回收)
既然是垃圾回收线程CPU占用100%,那么说明我们的应用的JVM内存使用有问题,借助jstat查看JVM的内存信息如下:
jstat -gcutil pid 5000 #这里是说每隔5000毫秒打印异常JVM内存信息
存活区0 | 存活区1 | 伊甸区 | Old区 | 永久区 | 新生带GC次数 | 新生带GC时间 | Full GC次数 | Full GC时间 | GC的总时间 |
S0 | S1 | E | O | P | YGC | YGCT | FGC | FGCT | GCT |
0.00 | 0 | 100 | 100 | 98.75 | 584 | 13.28 | 1447 | 3699.659 | 3712.939 |
0.00 | 0 | 100 | 100 | 98.75 | 584 | 13.28 | 1447 | 3699.659 | 3712.939 |
0.00 | 0 | 100 | 100 | 98.75 | 584 | 13.28 | 1447 | 3699.659 | 3712.939 |
0.00 | 0 | 100 | 100 | 98.75 | 584 | 13.28 | 1448 | 3702.135 | 3715.416 |
0.00 | 0 | 100 | 100 | 98.75 | 584 | 13.28 | 1448 | 3702.135 | 3715.416 |
存活区0和存活区1的内存占用都是0%,伊甸区使用100%,Old区使用也是100%,Full GC的次数达到1448(3个小时内,差不多9s做一次Full GC,每次Full GC花费2.56s)
也就是说我们的应用频繁的在做Full GC,而且Full GC消耗的时间也比较长,应用在做Full GC是整个应用是会阻塞的,所以在这种情况下我们的应用几乎是不可用的。
什么情况下会引发Full GC呢?参考下图:
Old区内存不够是JVM会触发Full GC,由于Old区一直是满的,所以会频繁触发Full GC,但是这个频度也不高,应该不至于导致CPU使用100%,我们用的是Parallel GC(并行GC),并行GC是说在新生带会采取多线程来进行垃圾回收,由于我们Eden区也是满的,所以GC的线程会CPU占用100%。
怎么查看我们的JVM每个区的内存大小情况呢?用jstat -gccapacity
新生带最小 | 新生带最大 | 新生带当前 | 存活区 | 存活区 | 伊甸区 | 老年带最小 | 老年带最大 | 老年带当前 | Old区内存占用 | 永久区最小 | 永久区最大 | 永久区当前 | 永久区内存占用 | 新生带GC次数 | Full GC 次数 |
NGCMN | NGCMX | NGC | S0C | S1C | EC | OGCMN | OGCMX | OGC | OC | PGCMN | PGCMX | PGC | PC | YGC | FGC |
21824 | 349504 | 64384 | 2112 | 3904 | 56448 | 43712 | 699072 | 178496 | 178496 | 16384 | 65536 | 35712 | 35712 | 146 | 9 |
21.3125 | 341.3125 | 62.875 | 2.0625 | 3.8125 | 55.125 | 42.6875 | 682.6875 | 174.3125 | 174.3125 | 16 | 64 | 34.875 | 34.875 |
我们的Eden区较小,这个可能会触发JVM的一个BUG(1.6u18前的版本,我们的版本是:java version "1.6.0_37")正好在这个范围内,具体信息查看:http://www.oschina.net/question/1092_24066
尝试升级jdk版本或者调整JVM内存参数解决该问题。