3回复
3年前
重启后YGC时间较长,经历一次FGC后YGC下降明显,怎么排查
我们这边遇到一个情况是,每次重启YGC大约60~80ms,FGC后YGC降到20ms~30ms,这个一般怎么排查好呢?
JVM参数
-Xms10g -Xmx10g -Xmn8g -XX:MetaspaceSize=2g -XX:MaxMetaspaceSize=2g -XX:MinMetaspaceFreeRatio=0 -XX:MaxMetaspaceFreeRatio=100 -XX:+UseConcMarkSweepGC -XX:+UseCMSCompactAtFullCollection -XX:CMSInitiatingOccupancyFraction=60 -XX:+CMSParallelRemarkEnabled -XX:SoftRefLRUPolicyMSPerMB=0 -XX:+CMSClassUnloadingEnabled -XX:SurvivorRatio=8 -XX:+DisableExplicitGC -XX:-OmitStackTraceInFastThrow -XX:+PrintReferenceGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 -XX:+PrintHeapAtGC
重启后稳定一段时间后YGC日志
{Heap before GC invocations=30 (full 0):
par new generation total 7549760K, used 6799988K [0x0000000540000000, 0x0000000740000000, 0x0000000740000000)
eden space 6710912K, 100% used [0x0000000540000000, 0x00000006d99a0000, 0x00000006d99a0000)
from space 838848K, 10% used [0x00000006d99a0000, 0x00000006df09d2b0, 0x000000070ccd0000)
to space 838848K, 0% used [0x000000070ccd0000, 0x000000070ccd0000, 0x0000000740000000)
concurrent mark-sweep generation total 2097152K, used 190228K [0x0000000740000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 270917K, capacity 288719K, committed 288896K, reserved 1306624K
class space used 29534K, capacity 32617K, committed 32640K, reserved 1048576K
2021-01-21T10:44:25.801+0800: 798.446: [GC (Allocation Failure) 2021-01-21T10:44:25.802+0800: 798.446: [ParNew2021-01-21T10:44:25.866+0800: 798.510: [SoftReference, 446 refs, 0.0001675 secs]2021-01-21T10:44:25.866+0800: 798.511: [WeakReference, 5504 refs, 0.0004158 secs]2021-01-21T10:44:25.866+0800: 798.511: [FinalReference, 3469 refs, 0.0013003 secs]2021-01-21T10:44:25.868+0800: 798.512: [PhantomReference, 1 refs, 9 refs, 0.0000927 secs]2021-01-21T10:44:25.868+0800: 798.512: [JNI Weak Reference, 0.0001262 secs]: 6799988K->94101K(7549760K), 0.0667137 secs] 6990217K->286240K(9646912K), 0.0679152 secs] [Times: user=0.35 sys=0.00, real=0.07 secs]
Heap after GC invocations=31 (full 0):
par new generation total 7549760K, used 94101K [0x0000000540000000, 0x0000000740000000, 0x0000000740000000)
eden space 6710912K, 0% used [0x0000000540000000, 0x0000000540000000, 0x00000006d99a0000)
from space 838848K, 11% used [0x000000070ccd0000, 0x00000007128b5618, 0x0000000740000000)
to space 838848K, 0% used [0x00000006d99a0000, 0x00000006d99a0000, 0x000000070ccd0000)
concurrent mark-sweep generation total 2097152K, used 192138K [0x0000000740000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 270917K, capacity 288719K, committed 288896K, reserved 1306624K
class space used 29534K, capacity 32617K, committed 32640K, reserved 1048576K
}
这个时候手动触发FGC,YGC日志如下
{Heap before GC invocations=184 (full 1):
par new generation total 7549760K, used 6759945K [0x0000000540000000, 0x0000000740000000, 0x0000000740000000)
eden space 6710912K, 100% used [0x0000000540000000, 0x00000006d99a0000, 0x00000006d99a0000)
from space 838848K, 5% used [0x000000070ccd0000, 0x000000070fcb26b8, 0x0000000740000000)
to space 838848K, 0% used [0x00000006d99a0000, 0x00000006d99a0000, 0x000000070ccd0000)
concurrent mark-sweep generation total 2097152K, used 286653K [0x0000000740000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 236071K, capacity 253147K, committed 313856K, reserved 1327104K
class space used 25637K, capacity 28467K, committed 35328K, reserved 1048576K
2021-01-21T11:31:21.122+0800: 3613.767: [GC (Allocation Failure) 2021-01-21T11:31:21.123+0800: 3613.767: [ParNew2021-01-21T11:31:21.138+0800: 3613.783: [SoftReference, 368 refs, 0.0001248 secs]2021-01-21T11:31:21.138+0800: 3613.783: [WeakReference, 517 refs, 0.0000651 secs]2021-01-21T11:31:21.138+0800: 3613.783: [FinalReference, 3727 refs, 0.0014593 secs]2021-01-21T11:31:21.140+0800: 3613.785: [PhantomReference, 0 refs, 0 refs, 0.0000123 secs]2021-01-21T11:31:21.140+0800: 3613.785: [JNI Weak Reference, 0.0001213 secs]: 6759945K->48233K(7549760K), 0.0180800 secs] 7046598K->336004K(9646912K), 0.0192935 secs] [Times: user=0.12 sys=0.00, real=0.02 secs]
Heap after GC invocations=185 (full 1):
par new generation total 7549760K, used 48233K [0x0000000540000000, 0x0000000740000000, 0x0000000740000000)
eden space 6710912K, 0% used [0x0000000540000000, 0x0000000540000000, 0x00000006d99a0000)
from space 838848K, 5% used [0x00000006d99a0000, 0x00000006dc8ba6b0, 0x000000070ccd0000)
to space 838848K, 0% used [0x000000070ccd0000, 0x000000070ccd0000, 0x0000000740000000)
concurrent mark-sweep generation total 2097152K, used 287771K [0x0000000740000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 236071K, capacity 253147K, committed 313856K, reserved 1327104K
class space used 25637K, capacity 28467K, committed 35328K, reserved 1048576K
}
2021-01-21T11:31:21.142+0800: 3613.787: Total time for which application threads were stopped: 0.0259542 seconds, Stopping threads took: 0.0009365 seconds
从日志上排除了Reference和safepoint原因,请教一下大家,有没有思路优化?
3151 阅读