GCOverheadLimit does not work ?
David Tavoularis
david.tavoularis at mycom-int.com
Sat Jun 7 10:58:38 PDT 2008
Hi,
It seems that the mechanism GCOverheadLimit did not trigger, even if more than 98% of the total time is spent in garbage collection and less than 2% of the heap is recovered. The process spent 3 hours in this state, performing Full GC after Full GC.
I am using Parallel Collector on Java6u4/Solaris9. Is it a bug or maybe I do not understand this feature ?
"TimeStamp","GC duration","Duration between 2 FullGC"
57356.444 27.46 27.471
57383.915 27.14 27.137
57411.052 27.63 27.738
57438.79 33.72 33.724
57472.514 30.07 30.087
57502.601 27.84 27.842
57530.443 28.46 28.519
57558.962 29.03 29.032
57587.994 29.31 29.321
Full GC logs are available at http://people.via.ecp.fr/~tony/tmp/gc_200802282216.zip
Thanks in advance
--
David Tavoularis
Command line :
/usr/jdk/instances/jdk1.6.0/jre/bin/java -server -Xms3072m -Xmx3072m -XX:+UseParallelGC -XX:+AggressiveHeap -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:+HeapDumpOnOutOfMemoryError ...
Java version : "1.6.0_04" on Solaris 9 (Sparc)
Java(TM) SE Runtime Environment (build 1.6.0_04-b12)
Java HotSpot(TM) Server VM (build 10.0-b19, mixed mode)
Extract of the GC logs :
57356.444: [Full GC [PSYoungGen: 262144K->260911K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1571631K(1627904K) [PSPermGen: 17242K->17241K(20480K)], 27.4570953 secs] [Times: user=27.46 sys=0.00, real=27.46 secs]
Heap after GC invocations=836 (full 530):
PSYoungGen total 317184K, used 260911K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 99% used [0xcc000000,0xdbecbdd0,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6618,0x79400000)
}
Total time for which application threads were stopped: 54.7390786 seconds
Application time: 0.0001805 seconds
Total time for which application threads were stopped: 0.0050949 seconds
Application time: 0.0000762 seconds
Total time for which application threads were stopped: 0.0015181 seconds
Application time: 0.0006421 seconds
{Heap before GC invocations=837 (full 531):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17243K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6da8,0x79400000)
57383.915: [Full GC [PSYoungGen: 262144K->262144K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1572863K(1627904K) [PSPermGen: 17243K->17243K(20480K)], 27.1362406 secs] [Times: user=27.14 sys=0.00, real=27.14 secs]
Heap after GC invocations=837 (full 531):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17243K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6da8,0x79400000)
}
{Heap before GC invocations=838 (full 532):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17243K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6da8,0x79400000)
57411.052: [Full GC [PSYoungGen: 262144K->260919K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1571639K(1627904K) [PSPermGen: 17243K->17241K(20480K)], 27.6282006 secs] [Times: user=27.63 sys=0.00, real=27.63 secs]
Heap after GC invocations=838 (full 532):
PSYoungGen total 317184K, used 260919K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 99% used [0xcc000000,0xdbecddc8,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6658,0x79400000)
}
Total time for which application threads were stopped: 54.8192590 seconds
Application time: 0.0001949 seconds
Total time for which application threads were stopped: 0.0048801 seconds
Application time: 0.0000836 seconds
Total time for which application threads were stopped: 0.0011786 seconds
Application time: 0.0007086 seconds
{Heap before GC invocations=839 (full 533):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d67f0,0x79400000)
57438.790: [Full GC [PSYoungGen: 262144K->262144K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1572863K(1627904K) [PSPermGen: 17241K->17241K(20480K)], 33.7237730 secs] [Times: user=33.29 sys=0.00, real=33.72 secs]
Heap after GC invocations=839 (full 533):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d67f0,0x79400000)
}
{Heap before GC invocations=840 (full 534):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d67f0,0x79400000)
57472.514: [Full GC [PSYoungGen: 262144K->260951K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1571671K(1627904K) [PSPermGen: 17241K->17241K(20480K)], 30.0724968 secs] [Times: user=29.98 sys=0.01, real=30.07 secs]
Heap after GC invocations=840 (full 534):
PSYoungGen total 317184K, used 260951K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 99% used [0xcc000000,0xdbed5e18,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17241K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d67f0,0x79400000)
}
Total time for which application threads were stopped: 63.8515774 seconds
Application time: 0.0002396 seconds
Total time for which application threads were stopped: 0.0055494 seconds
Application time: 0.0000822 seconds
Total time for which application threads were stopped: 0.0013594 seconds
Application time: 0.0010679 seconds
{Heap before GC invocations=841 (full 535):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6858,0x79400000)
57502.601: [Full GC [PSYoungGen: 262144K->262144K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1572863K(1627904K) [PSPermGen: 17242K->17242K(20480K)], 27.8416247 secs] [Times: user=27.84 sys=0.00, real=27.84 secs]
Heap after GC invocations=841 (full 535):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6858,0x79400000)
}
{Heap before GC invocations=842 (full 536):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6858,0x79400000)
57530.443: [Full GC [PSYoungGen: 262144K->260976K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1571696K(1627904K) [PSPermGen: 17242K->17242K(20480K)], 28.4587198 secs] [Times: user=28.22 sys=0.00, real=28.46 secs]
Heap after GC invocations=842 (full 536):
PSYoungGen total 317184K, used 260976K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 99% used [0xcc000000,0xdbedc060,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d6858,0x79400000)
}
Total time for which application threads were stopped: 56.3591418 seconds
Application time: 0.0002362 seconds
{Heap before GC invocations=843 (full 537):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d68c8,0x79400000)
57558.962: [Full GC [PSYoungGen: 262144K->262144K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1572863K(1627904K) [PSPermGen: 17242K->17242K(20480K)], 29.0315209 secs] [Times: user=28.92 sys=0.00, real=29.03 secs]
Heap after GC invocations=843 (full 537):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d68c8,0x79400000)
}
{Heap before GC invocations=844 (full 538):
PSYoungGen total 317184K, used 262144K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 100% used [0xcc000000,0xdc000000,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d68c8,0x79400000)
57587.994: [Full GC [PSYoungGen: 262144K->260978K(317184K)] [PSOldGen: 1310719K->1310719K(1310720K)] 1572863K->1571698K(1627904K) [PSPermGen: 17242K->17242K(20480K)], 29.3142086 secs] [Times: user=29.29 sys=0.00, real=29.31 secs]
Heap after GC invocations=844 (full 538):
PSYoungGen total 317184K, used 260978K [0xcc000000, 0xfc000000, 0xfc000000)
eden space 262144K, 99% used [0xcc000000,0xdbedc888,0xdc000000)
from space 55040K, 0% used [0xf8a40000,0xf8a40000,0xfc000000)
to space 262144K, 0% used [0xdc000000,0xdc000000,0xec000000)
PSOldGen total 1310720K, used 1310719K [0x7c000000, 0xcc000000, 0xcc000000)
object space 1310720K, 99% used [0x7c000000,0xcbfffff8,0xcc000000)
PSPermGen total 20480K, used 17242K [0x78000000, 0x79400000, 0x7c000000)
object space 20480K, 84% used [0x78000000,0x790d68c8,0x79400000)
}
Total time for which application threads were stopped: 58.3541271 seconds
More information about the hotspot-gc-use
mailing list