Java Garbage Collector Allocation Failure

Question

I am running my java application on machine having 8GB Memory and 4 CPU. But after running application for longer period with stress testing, Garbage collector problems are observed as memory is completely full and seems that gc cycles taking longer time to complete, but i am not able to figure out the possible cause and its resolutions. There is not much difference in avg latency of our requests to complete. But it is not able to serve much threads concurrently.

I have started my application with following params

-Xms4096M -Xmx4096M 
-XX:MaxPermSize=512M 
-XX:PermSize=512m 
-XX:+UseConcMarkSweepGC 
-XX:+HeapDumpOnOutOfMemoryError 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDetails 
-XX:+PrintGCApplicationStoppedTime 
-XX:+PrintGCApplicationConcurrentTime 
-XX:+PrintHeapAtGC 
-Xloggc:/root/tomcat_logs/gc_logs.log

Output of top command

top - 11:24:03 up 44 days, 23:45,  1 user,  load average: 0.39, 0.47, 0.65
Tasks: 158 total,   1 running, 157 sleeping,   0 stopped,   0 zombie
Cpu(s): 18.8%us,  2.1%sy,  0.0%ni, 64.2%id, 12.9%wa,  0.2%hi,  1.8%si,  0.0%st
Mem:   7672012k total,  7270396k used,   401616k free,   238468k buffers
Swap:  5238776k total,    34584k used,  5204192k free,  2390820k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                           
15811 root      20   0 7919m 4.1g   9m S 101.1 55.9   4134:37 java

Sample GC Logs after filling of memory

{Heap before GC invocations=193901 (full 4):
 par new generation   total 306688K, used 274312K [0x00000006c0000000, 0x00000006d4cc0000, 0x00000006d4cc0000)
  eden space 272640K, 100% used [0x00000006c0000000, 0x00000006d0a40000, 0x00000006d0a40000)
  from space 34048K,   4% used [0x00000006d2b80000, 0x00000006d2d222c8, 0x00000006d4cc0000)
  to   space 34048K,   0% used [0x00000006d0a40000, 0x00000006d0a40000, 0x00000006d2b80000)
 concurrent mark-sweep generation total 3853568K, used 687930K [0x00000006d4cc0000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 58528K, capacity 59902K, committed 61732K, reserved 1103872K
  class space    used 6866K, capacity 7109K, committed 7464K, reserved 1048576K
89974.407: [GC (Allocation Failure) 89974.407: [ParNew: 274312K->1655K(306688K), 0.0101861 secs] 962243K->689622K(4160256K), 0.0104010 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 
Heap after GC invocations=193902 (full 4):
 par new generation   total 306688K, used 1655K [0x00000006c0000000, 0x00000006d4cc0000, 0x00000006d4cc0000)
  eden space 272640K,   0% used [0x00000006c0000000, 0x00000006c0000000, 0x00000006d0a40000)
  from space 34048K,   4% used [0x00000006d0a40000, 0x00000006d0bdded0, 0x00000006d2b80000)
  to   space 34048K,   0% used [0x00000006d2b80000, 0x00000006d2b80000, 0x00000006d4cc0000)
 concurrent mark-sweep generation total 3853568K, used 687966K [0x00000006d4cc0000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 58528K, capacity 59902K, committed 61732K, reserved 1103872K
  class space    used 6866K, capacity 7109K, committed 7464K, reserved 1048576K
}
89974.418: Total time for which application threads were stopped: 0.0127352 seconds
89974.988: Application time: 0.5703336 seconds

I wanted to come on conclusion why memory is that much filled and what i can do to overcome it so that i can run my app for longer term with higher load. Please help me doing so.

You can also set different values for the initial and Max heap size. This way the GC will sweep regularly for the dereferenced objects and your GC cycles will be short. Also configure your jconsole to check for memory leaks! — Ravi Ranjan, Feb 27 '16 at 06:23

score 0 · Answer 1 · answered Feb 27 '16 at 06:06

Basically u are facing possible memory leak. With YourKIt (or profiler of your choice), run your application, and in due course of time, Force garbage collection at regular intervals, Then check which Objects are still getting accumulated despite force gc. It could be a time consuming activity but will pay off in the end.

Possible cause could be ClassLoader leaks, weak references, badly implemented caching or anything else.

score 0 · Answer 2 · answered Feb 27 '16 at 06:30

There is no problem visible from the log excerpt you presented.

[Times: user=0.04 sys=0.00, real=0.01 secs]

Collection took 10ms wall time.

concurrent mark-sweep generation total 3853568K, used 687966K [0x00000006d4cc0000, 0x00000007c0000000, 0x00000007c0000000)

old generation is only 680MB/3.8G full.

Although that's only a young gen collection, so maybe you have posted an irrelvant part of your log. Maybe because you think "failure" means "bad"? This is not the case. It's just the trigger for the young collection, meaning that an allocation could not be satisfied without first collecting the young generation.

You may want to run the whole thing through GCViewer to see if you're actually experiencing GC problems.

Java Garbage Collector Allocation Failure

2 Answers2