Heap OOM for no apparent reason?

[Charles K Pepperdine]

+1, can't see anything in these logs that indicates you're heading to a OOME due to Java heap. But, incomplete log...

Regards,
Kirk

On Jun 1, 2011, at 7:24 PM, Jon Masamitsu wrote:

> Raman,
> 
> The gc.log looks like it has the young collections
> filtered out.  Is that right?  If so, please upload
> the complete log.
> 
> Jon
> 
> On 05/27/11 10:57, Raman Gupta wrote:
>> I am getting a heap OOM for no apparent reason. Normally permanent generation size or a large finalization queue would be culprits for this sort of OOM, but AFAICT GC logs and heap dump show that neither is the case here. There is also no native code being executed.
>> 
>> Linux RHEL 5.6
>> 
>> java version "1.6.0_24"
>> Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
>> Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode)
>> 
>> (I have also tried it with 1.6.0_25 64-bit and 1.6.0_25 32-bit with the same OOM result for both, but the logs below are from 1.6.0_24 64-bit).
>> 
>> Startup parameters:
>> 
>> -server
>> -Xms256m
>> -Xmx256m
>> -XX:+HeapDumpOnOutOfMemoryError
>> -XX:MaxPermSize=64m
>> -verbose:gc
>> -XX:-UseGCOverheadLimit
>> -XX:+DisableExplicitGC
>> -XX:+UseParallelGC
>> -XX:+UseFastAccessorMethods
>> -XX:AdaptiveSizePolicyOutputInterval=1
>> -XX:+PrintGCDateStamps
>> -XX:+PrintGCTimeStamps
>> -XX:+PrintGCDetails
>> -XX:+PrintGCApplicationConcurrentTime
>> -XX:+PrintGCApplicationStoppedTime
>> 
>> The complete GC log is available here:
>> 
>> http://dl.dropbox.com/u/3430279/gc.log
>> 
>> but here is a short snippet from that log before and after the OOM:
>> 
>> 2011-05-27T11:35:18.214-0400: 147.823: [Full GC [PSYoungGen: 7662K->0K(72896K)] [PSOldGen: 169093K->62518K(174784K)] 176755K->62518K(247680K) [PSPermGen: 27342K->27342K(55232K)], 0.8074580 secs] [Times: user=0.29 sys=0.03, real=0.81 secs]
>> 2011-05-27T11:35:19.022-0400: 148.632: [Full GC [PSYoungGen: 0K->0K(57856K)] [PSOldGen: 62518K->52158K(174784K)] 62518K->52158K(232640K) [PSPermGen: 27342K->26866K(61056K)], 0.3614330 secs] [Times: user=0.32 sys=0.02, real=0.37 secs]
>> Total time for which application threads were stopped: 1.2760680 seconds
>> java.lang.OutOfMemoryError: Java heap space
>> Dumping heap to java_pid18706.hprof ...
>> Application time: 0.9442610 seconds
>> Total time for which application threads were stopped: 2.4584870 seconds
>> Heap dump file created [83874513 bytes in 3.330 secs]
>> 2011-05-27T11:35:30.942-0400: 160.552: [Full GC [PSYoungGen: 2624K->0K(44800K)] [PSOldGen: 86916K->76124K(174784K)] 89540K->76124K(219584K) [PSPermGen: 26902K->26902K(58880K)], 0.2801510 secs] [Times: user=0.28 sys=0.00, real=0.28 secs]
>> 
>> Note that:
>> 
>> 1) I can reproduce this easily.
>> 
>> 2) This seems to happen only once shortly after load is applied to the system shortly after startup -- after that everything seems fine (though I haven't yet verified this with a longer test).
>> 
>> 3) There is *always* a Full GC showing a young generation 0K->0K collection before this happens.
>> 
>> 4) There seems to be plenty of space in the tenured generation as well as in permanent at OOM time.
>> 
>> 5) The heap dump in pid18706.hprof shows only 70 MB of live objects in the heap.
>> 
>> 6) The heap dump in pid18706.hprof shows no objects in the finalization queue.
>> 
>> 7) I note the OutOfMemoryError in the log does not have any stack trace associated with it as is normally present.
>> 
>> 8) When running the JVM with hprof sites profiling turned on (-agentlib:hprof=heap=sites) no OOM occurs (though again I did not try a very long test).
>> 
>> I'm not sure what else to try or where else to look. Any suggestions?
>> 
>> Cheers,
>> Raman Gupta