CODEWITHSUNDEEP
javagarbage-collectionjvm
Kay
Kay

Reputation: 59

Why Full GC Continue happens?

GC Log

2017-11-08T01:48:24.133+0800: 63444.343: [Full GC [PSYoungGen: 918116K->0K(1494016K)] [ParOldGen: 2271465K->1273508K(2555904K)] 3189581K->1273508K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8804710 secs] [Times: user=8.48 sys=0.03, real=0.89 secs] 
2017-11-08T01:48:32.132+0800: 63452.342: [Full GC [PSYoungGen: 855154K->0K(1494016K)] [ParOldGen: 2287221K->1322801K(2555904K)] 3142375K->1322801K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8771230 secs] [Times: user=8.40 sys=0.00, real=0.88 secs] 
2017-11-08T01:48:40.132+0800: 63460.342: [Full GC [PSYoungGen: 902479K->0K(1494016K)] [ParOldGen: 2336514K->1256452K(2555904K)] 3238994K->1256452K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8855200 secs] [Times: user=8.84 sys=0.01, real=0.89 secs] 
2017-11-08T01:48:48.130+0800: 63468.340: [Full GC [PSYoungGen: 882590K->0K(1494016K)] [ParOldGen: 2270165K->1256453K(2555904K)] 3152755K->1256453K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8677890 secs] [Times: user=8.42 sys=0.01, real=0.87 secs] 
2017-11-08T01:48:56.133+0800: 63476.343: [Full GC [PSYoungGen: 861301K->0K(1494016K)] [ParOldGen: 2270166K->1322782K(2555904K)] 3131468K->1322782K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8013890 secs] [Times: user=7.17 sys=0.00, real=0.81 secs] 
2017-11-08T01:49:04.127+0800: 63484.337: [Full GC [PSYoungGen: 898990K->0K(1494016K)] [ParOldGen: 2336494K->1256170K(2555904K)] 3235485K->1256170K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8792570 secs] [Times: user=8.35 sys=0.00, real=0.88 secs] 
2017-11-08T01:49:12.132+0800: 63492.342: [Full GC [PSYoungGen: 885368K->0K(1494016K)] [ParOldGen: 2269882K->1256088K(2555904K)] 3155251K->1256088K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8924250 secs] [Times: user=8.41 sys=0.03, real=0.89 secs] 
2017-11-08T01:49:20.125+0800: 63500.335: [Full GC [PSYoungGen: 858394K->0K(1494016K)] [ParOldGen: 2269801K->1322779K(2555904K)] 3128195K->1322779K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8686500 secs] [Times: user=8.32 sys=0.00, real=0.87 secs] 
2017-11-08T01:49:28.128+0800: 63508.338: [Full GC [PSYoungGen: 902214K->0K(1494016K)] [ParOldGen: 2336492K->1256045K(2555904K)] 3238707K->1256045K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8648800 secs] [Times: user=8.45 sys=0.01, real=0.87 secs] 
2017-11-08T01:49:36.128+0800: 63516.338: [Full GC [PSYoungGen: 883133K->0K(1494016K)] [ParOldGen: 2269758K->1256037K(2555904K)] 3152892K->1256037K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8212970 secs] [Times: user=7.20 sys=0.15, real=0.83 secs] 
2017-11-08T01:49:44.128+0800: 63524.338: [Full GC [PSYoungGen: 875607K->0K(1494016K)] [ParOldGen: 2269750K->1322438K(2555904K)] 3145357K->1322438K(4049920K) [PSPermGen: 101780K->101780K(131072K)], 0.8001900 secs] [Times: user=7.11 sys=0.00, real=0.80 secs]

JVM options

-Xms4096m 
-Xmx4096m 
-Xmn1600m 
-XX:PermSize=128M 
-XX:MaxPermSize=256M 
-XX:+PrintGCDetails 
-verbose:gc 
-XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDateStamps 
-XX:-HeapDumpOnOutOfMemoryError

Frequent Full GC happened even though ParOldGen plus ParOldGen lower than Xmx4096m. Can anyone analyze it for me? How to optimize this situation?

Upvotes: 2

Views: 983

Answers (1)

Alexey Ragozin
Alexey Ragozin

Reputation: 8409

Looking at your GC logs, you have direct allocation in old space. Once old space exhausted, full GC triggered (even though young have some spare space). Direct allocation in old space may be caused by object size, exceeding remaining Eden size (about 300 MiB for your heap geometry).

Provided,

  • that you are allocating huge objects
  • these objects are short lived (each GC recovers ~2 GiB)

I cannot suggest your any GC tuning strategy (unless you are ready to dramatically increase heap size).

I would suggest you to investigate nature of huge object being allocated. Heap dump or Mission Control (see "Allocation outside TLAB") should help.

Upvotes: 2

Related Questions