This discussion is archived
0 Replies Latest reply: May 11, 2010 7:05 AM by 843798 RSS

Java Memory Incresease Exponentially

843798 Newbie
Currently Being Moderated
Hi All ,


When my program runs for a long time, the memory was increasing by time and the program halts some time . The following gives a brief of my issues,
* The JVM memory utilized was increasing by time
* The performance was affected due to long GC pauses
* More CPU utilization time to time

I tried to do some trouble shooting with the JVM tools, the details are,

GC snapshot time to time
--------------------------------------------------------------

0.000: [GC [PSYoungGen: 5510K->1206K(78848K)] 5510K->1206K(254976K), 0.0354727 secs]
0.036: [Full GC [PSYoungGen: 1206K->0K(78848K)] [PSOldGen: 0K->864K(176128K)] 1206K->864K(254976K) [PSPermGen: 4019K->4019K(16384K)]
60.136: [GC [PSYoungGen: 39806K->2726K(78848K)] 40671K->3590K(254976K), 0.0476875 secs]
60.184: [Full GC [PSYoungGen: 2726K->0K(78848K)] [PSOldGen: 864K->3219K(176128K)] 3590K->3219K(254976K) [PSPermGen: 9816K->9816K(16]
...
202741.476: [GC [PSYoungGen: 8679K->511K(78848K)] 150325K->142157K(254976K), 0.0068342 secs]
202741.483: [Full GC [PSYoungGen: 511K->0K(78848K)] [PSOldGen: 141645K->141494K(176128K)] 14
....

340190.306: [Full GC [PSYoungGen: 61381K->54854K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 241605K->235078K(259072K) [PSPermGe]
340255.216: [Full GC [PSYoungGen: 65681K->55436K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 245905K->235660K(259072K) [PSPermGe]
340320.186: [Full GC [PSYoungGen: 66380K->52100K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 246604K->232324K(259072K) [PSPermGe]
340385.186: [Full GC [PSYoungGen: 60744K->55407K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 240968K->235631K(259072K) [PSPermGe]
340450.576: [Full GC [PSYoungGen: 61949K->55514K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 242173K->235738K(259072K) [PSPermGe]
340515.756: [Full GC [PSYoungGen: 66607K->55615K(78848K)] [PSOldGen: 180224K->180224K(180224K)] 246831K->235839K(259072K) [PSPermGe]

....
421720.996: [GC [PSYoungGen: 12053K->535K(78848K)] 296887K->285368K(615424K), 0.0072620 secs]
421721.003: [Full GC [PSYoungGen: 535K->0K(78848K)] [PSOldGen: 284833K->284938K(536576K)] 285368K->284938K(615424K) [PSPermGen: 10020K->10020K(16384K)], 5.8750348 secs]
421786.886: [GC [PSYoungGen: 8392K->511K(78848K)] 293330K->285449K(615424K), 0.0080966 secs]
421786.894: [Full GC [PSYoungGen: 511K->0K(78848K)] [PSOldGen: 284938K->285014K(536576K)] 285449K->285014K(615424K) [PSPermGen: 10025K->10025K(16384K)], 5.9864552 secs]
421852.886: [GC [PSYoungGen: 5909K->487K(78848K)] 290923K->285501K(615424K), 0.0074509 secs]
421852.893: [Full GC [PSYoungGen: 487K->0K(78848K)] [PSOldGen: 285014K->284900K(536576K)] 285501K->284900K(615424K) [PSPermGen: 10030K->10010K(16384K)], 6.1571002 secs]
421919.056: [GC [PSYoungGen: 4533K->559K(78848K)] 289434K->285459K(615424K), 0.0074119 secs]
421919.063: [Full GC [PSYoungGen: 559K->0K(78848K)] [PSOldGen: 284900K->284976K(536576K)] 285459K->284976K(615424K) [PSPermGen: 10015K->10015K(16384K)], 6.1046790 secs]
421985.176: [GC [PSYoungGen: 7510K->527K(78848K)] 292487K->285503K(615424K), 0.0068276 secs]

Hardware:
-------------------------------
Solaris Sparc

Jmap -heap details:
-------------------------------
JVM version is 1.5.0_06-b05

using thread-local object allocation.
Parallel GC with 32 thread(s)

Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 1073741824 (1024.0MB)
NewSize = 2228224 (2.125MB)
MaxNewSize = 4294901760 (4095.9375MB)
OldSize = 1441792 (1.375MB)
NewRatio = 2
SurvivorRatio = 32
PermSize = 16777216 (16.0MB)
MaxPermSize = 67108864 (64.0MB)

Jmap -histo details:
-------------------------------
Unknown oop at 0xe3448e30
Oop's klass is null
Unknown oop at 0xe34513e0
Oop's klass is null
Unknown oop at 0xe34a0698
Oop's klass is null
...
Debugger attached successfully.
Server compiler detected.
JVM version is 1.5.0_06-b05
Iterating over heap. This may take a while...
Object Histogram:

Size Count Class description
-------------------------------------------------------
310075456 9689858 java.util.concurrent.locks.AbstractQueuedSynchronizer$Node
2656968 22063 * ConstMethodKlass
1592632 22063 * MethodKlass
1498288 38145 * SymbolKlass
1109992 2005 * ConstantPoolKlass


The heap memory was taken by default, JVM heap properties was not modified.

I have following questions based on the above,
* Why there was lot of Full GC's and even it occurs once after a Minor GC cycle? I thought Full GC occurs when there is a need to reallocate/free memory when the heap is near close to heap size.
* I found there was a memory leak bug related to java.util.concurrent.locks.AbstractQueuedSynchronizer$Node (http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6460501). Here they have told the problem was due to Semaphore timed tryAcquire(). In my case i'm using tryAcquire without time wait, is that valid in this case?
* The program works in RMI environment, which results in RMI Thread timeouts , does this can create any memory leaks ?
* Does anyone had similar issue and fixed it ??