Java6u7 : 2 very long Parallel GC (24&30min) without any specific reason

[David Tavoularis]

Hi,

We had 2 very long duration of the Full GC (Parallel GC) running with Java 6u7 (64-bit Solaris), where GC took 24min and then 30min.
Usually, Full GC would hardly take more than 2 minutes.

We also noticed that the "real" measurement usually comes close to the sum of the "user" and "sys" measurement, but here it outpasses the figures, see :
user=47.85 sys=9.84, real=1450.70 secs

Any idea what to check from here ?


As a workaround, I would like to implement the property "-XX:MaxGCPauseMillis=60000" (10min max for a Full GC). Do you think it is a good idea ?

Thanks in advance

-- 
David




[...]
{Heap before GC invocations=1707 (full 39):
 PSYoungGen      total 3757056K, used 1158717K [0xfffffffe7f000000, 0xffffffff78800000, 0xffffffff78800000)
  eden space 3436160K, 32% used [0xfffffffe7f000000,0xfffffffec238f468,0xffffffff50ba0000)
  from space 320896K, 17% used [0xffffffff50ba0000,0xffffffff543a0000,0xffffffff64500000)
  to   space 308800K, 0% used [0xffffffff65a70000,0xffffffff65a70000,0xffffffff78800000)
 PSOldGen        total 16396288K, used 4817606K [0xfffffffa96400000, 0xfffffffe7f000000, 0xfffffffe7f000000)
  object space 16396288K, 29% used [0xfffffffa96400000,0xfffffffbbc4b1b58,0xfffffffe7f000000)
 PSPermGen       total 94208K, used 73744K [0xfffffffa76400000, 0xfffffffa7c000000, 0xfffffffa96400000)
  object space 94208K, 78% used [0xfffffffa76400000,0xfffffffa7ac04308,0xfffffffa7c000000)
37586.523: [Full GC (System) [PSYoungGen: 1158717K->0K(3757056K)] [PSOldGen: 4817606K->4825556K(16396288K)] 5976323K->4825556K(20153344K) [PSPermGen: 73744K->73744K(94208K)], 1450.6814969 secs] [Times: user=47.85 sys=9.84, real=1450.70 secs]
Heap after GC invocations=1707 (full 39):
 PSYoungGen      total 3757056K, used 0K [0xfffffffe7f000000, 0xffffffff78800000, 0xffffffff78800000)
  eden space 3436160K, 0% used [0xfffffffe7f000000,0xfffffffe7f000000,0xffffffff50ba0000)
  from space 320896K, 0% used [0xffffffff50ba0000,0xffffffff50ba0000,0xffffffff64500000)
  to   space 308800K, 0% used [0xffffffff65a70000,0xffffffff65a70000,0xffffffff78800000)
 PSOldGen        total 16396288K, used 4825556K [0xfffffffa96400000, 0xfffffffe7f000000, 0xfffffffe7f000000)
  object space 16396288K, 29% used [0xfffffffa96400000,0xfffffffbbcc75320,0xfffffffe7f000000)
 PSPermGen       total 94208K, used 73744K [0xfffffffa76400000, 0xfffffffa7c000000, 0xfffffffa96400000)
  object space 94208K, 78% used [0xfffffffa76400000,0xfffffffa7ac04308,0xfffffffa7c000000)
}
Total time for which application threads were stopped: 1450.8533550 seconds
[...]

-------------

[...]
Total time for which application threads were stopped: 0.0008307 seconds
Total time for which application threads were stopped: 0.0402369 seconds
{Heap before GC invocations=1731 (full 40):
 PSYoungGen      total 2841920K, used 795145K [0xfffffffe7f000000, 0xffffffff78800000, 0xffffffff78800000)
  eden space 1626624K, 2% used [0xfffffffe7f000000,0xfffffffe816825c0,0xfffffffee2480000)
  from space 1215296K, 62% used [0xffffffff2e530000,0xffffffff5c730000,0xffffffff78800000)
  to   space 1230592K, 0% used [0xfffffffee2480000,0xfffffffee2480000,0xffffffff2d640000)
 PSOldGen        total 16396288K, used 9942183K [0xfffffffa96400000, 0xfffffffe7f000000, 0xfffffffe7f000000)
  object space 16396288K, 60% used [0xfffffffa96400000,0xfffffffcf5129db8,0xfffffffe7f000000)
 PSPermGen       total 94208K, used 93469K [0xfffffffa76400000, 0xfffffffa7c000000, 0xfffffffa96400000)
  object space 94208K, 99% used [0xfffffffa76400000,0xfffffffa7bf47660,0xfffffffa7c000000)
42393.882: [Full GC (System) [PSYoungGen: 795145K->0K(2841920K)] [PSOldGen: 9942183K->9134638K(16396288K)] 10737328K->9134638K(19238208K) [PSPermGen: 93469K->70889K(98304K)], 1771.4421419 secs] [Times: user=120.88 sys=15.58, real=1771.45 secs] 
Heap after GC invocations=1731 (full 40):
 PSYoungGen      total 2841920K, used 0K [0xfffffffe7f000000, 0xffffffff78800000, 0xffffffff78800000)
  eden space 1626624K, 0% used [0xfffffffe7f000000,0xfffffffe7f000000,0xfffffffee2480000)
  from space 1215296K, 0% used [0xffffffff2e530000,0xffffffff2e530000,0xffffffff78800000)
  to   space 1230592K, 0% used [0xfffffffee2480000,0xfffffffee2480000,0xffffffff2d640000)
 PSOldGen        total 16396288K, used 9134638K [0xfffffffa96400000, 0xfffffffe7f000000, 0xfffffffe7f000000)
  object space 16396288K, 55% used [0xfffffffa96400000,0xfffffffcc3c8b928,0xfffffffe7f000000)
 PSPermGen       total 98304K, used 70889K [0xfffffffa76400000, 0xfffffffa7c400000, 0xfffffffa96400000)
  object space 98304K, 72% used [0xfffffffa76400000,0xfffffffa7a93a5e8,0xfffffffa7c400000)
}
Total time for which application threads were stopped: 1771.5992402 seconds
Total time for which application threads were stopped: 0.0666503 seconds
Total time for which application threads were stopped: 0.0978373 seconds
[...]

--------------

GC logs available at : http://dl.free.fr/qKoCs5q9F