1

I'm Using Java 7 update 76, and G1 garbage collector.

Periodically we experience full GCs occurring at small time intervals (every 4 to 5 seconds), it appears memory is being freed, but another full gc occurs very soon afterwards and appears to free a similar amount of memory again.

Does this indicate a heap fragmentation / garbage compaction issue?

Line 21068: 2015-05-27T04:58:38.527+0100: 2792829.022: [Full GC 3987M->236M(4096M), 0.6266670 secs]
Line 21084: 2015-05-27T04:58:46.744+0100: 2792837.238: [Full GC 3901M->237M(4096M), 0.6240680 secs]
Line 21101: 2015-05-27T04:58:51.303+0100: 2792841.797: [Full GC 3991M->238M(4096M), 0.6463980 secs]
Line 21118: 2015-05-27T04:58:55.561+0100: 2792846.055: [Full GC 3903M->238M(4096M), 0.6273730 secs]
Line 21130: 2015-05-27T04:58:59.747+0100: 2792850.241: [Full GC 3901M->238M(4096M), 0.6414350 secs]
Line 21146: 2015-05-27T04:59:04.128+0100: 2792854.623: [Full GC 3902M->237M(4096M), 0.6291800 secs]
Line 21158: 2015-05-27T04:59:08.363+0100: 2792858.857: [Full GC 3902M->239M(4096M), 0.6308080 secs]
Line 21169: 2015-05-27T04:59:12.536+0100: 2792863.031: [Full GC 3814M->240M(4096M), 0.6440340 secs]
Line 21185: 2015-05-27T04:59:18.000+0100: 2792868.495: [Full GC 3905M->239M(4096M), 0.6270340 secs]
Line 21197: 2015-05-27T04:59:22.217+0100: 2792872.711: [Full GC 3902M->239M(4096M), 0.6288050 secs]
Line 21208: 2015-05-27T04:59:26.389+0100: 2792876.883: [Full GC 3902M->239M(4096M), 0.6330140 secs]
Line 21224: 2015-05-27T04:59:30.610+0100: 2792881.104: [Full GC 3904M->239M(4096M), 0.6279680 secs]
Line 21236: 2015-05-27T04:59:34.758+0100: 2792885.253: [Full GC 3813M->239M(4096M), 0.6295690 secs]
Line 21247: 2015-05-27T04:59:38.928+0100: 2792889.422: [Full GC 3903M->239M(4096M), 0.6315110 secs]
Line 21258: 2015-05-27T04:59:43.260+0100: 2792893.754: [Full GC 3814M->240M(4096M), 0.6532740 secs]
Line 21274: 2015-05-27T04:59:49.461+0100: 2792899.955: [Full GC 3993M->239M(4096M), 0.6340010 secs]
Line 21286: 2015-05-27T04:59:53.765+0100: 2792904.260: [Full GC 3903M->240M(4096M), 0.6300460 secs]

Before this repeated full gc repeated behaviour happens the system can run fine for around a month ...

NottmTony
  • 447
  • 1
  • 6
  • 28
  • '3987M->236M(4096M),' and every 4-8 seconds, the heap is actually hitting 3.9G from 240M. Could it be that some rogue code is leaking like crazy? I mean, the memory is claimed by around 2.3G for every full GC cycle. Can't it be that the app is genuinely creating so many object? Some request, some method call looping over a huge data set ? – Praba Jun 03 '15 at 13:53
  • Yeah, we thought this was code related initially (still could be) but it runs fine for a month then goes wobbly ! – NottmTony Jun 03 '15 at 14:11
  • Have you taken thread dumps and object histogram dumps from the server while it was going wobbly? They will provide clues that as to who is responsible for the object churn without having to reproduce while in a debugger. – Chris K Jun 03 '15 at 14:15
  • Hi, we are in the process of investigating and reproducing this issue off-site - we are planning on doing this yes. Thanks – NottmTony Jun 03 '15 at 14:32
  • There is no indication of what other JVM flags you tried (like ‐XX:+UseConcMarkSweepGC, etc). If your working set is only 240M, and you allocate 4Gb in 4s, then you have 1Gb/s of garbage creation throughput. For server applications, you probably want throughput oriented collection; and for clients you want latency oriented collection. In any case, you may find that a small portion of the code is creating all that garbage. – Rob Jun 03 '15 at 18:05

2 Answers2

2

This is unlikely to be a G1 specific problem (try another collector and the same thing will probably happen). You have a very high churn rate going on within your app. Tools like yourkit are very good for tracking down the main offenders.

Chris K
  • 11,622
  • 1
  • 36
  • 49
  • 1
    I would start by looking at the memory saw tooth shape - whether it is a linear or quadratic climb. You can plot f(x), f(x)/x, f(x)/(x*x), f(x)/(ln(x)*x) side by side for some insight. The first suspect to rule out is almost always string append in a loop, or other immutable collection copy patterns with quadratic garbage creation. Avoiding allocation in the main hot loop is next. The garbage creation rate determines how often a collect must be triggered. – Rob Jun 03 '15 at 18:27
0

I used eclipse MAT and Your kit. Both are good. Couple of my friends are using class loader memory leak tool. I heard a lots of good about it. This is good article about this class loader memory leak prevention jar. Please note :- only with war.

bobs_007
  • 178
  • 1
  • 10