AW: Minor GCs grow longer after Full GC

[Andreas Müller]

Hi Thomas,

thanks for your helpful comments.

>Which exact version of Java were you using?
So far, we have been using Java 7_65 but we are going to switch to Java 8 these days. I will press to use 8_40+ following you recommendation.

> Yes, but it seems that in your case the perm gen (or one of those additional roots) seems to be the problem.
Good hint, but from what do you conclude that?
It's a good idea because we have recently decreased old gen and increased perm gen. 
We did that because a full perm gen triggered major GCs very frequently and with CMS this sometimes resulted in very long running (single-threaded) Full GCs. 
In the end we ditched CMS altogether to avoid that risk. As you can see from the plot, ParallelGC delivers reasonable Full GC runs of 3-5 seconds about once an hour. 
That's fine and more robust than CMS, which seems to be at odds with perm gen triggered major GCs: 95% of them were concurrent and below 1s but some took as much as 50s!
That's why I also tested G1 as an alternative.
  
>In 7u60 there have been some improvements to remembered set management from code cache. This often decreases the impact of this behavior, but does not remove it. Young GC times will still grow over time.
Code cache could be another source of trouble. Ours is huge (512 MB) for the same reason perm gen is huge.
Thanks for pointing at that, I did not take into account that code cache contains references to new gen objects, too.

Best regards
Andreas

-----Ursprüngliche Nachricht-----
Von: Thomas Schatzl [mailto:thomas.schatzl at oracle.com] 
Gesendet: Donnerstag, 22. Januar 2015 15:08
An: Andreas Müller
Cc: 'hotspot-gc-use at openjdk.java.net' (hotspot-gc-use at openjdk.java.net)
Betreff: Re: Minor GCs grow longer after Full GC

Hi Andreas,

On Thu, 2015-01-22 at 13:58 +0000, Andreas Müller wrote:
> Hi all,
>  
> for some time I have been looking at an application (Tomcat 7, Java 7 
> on Linux, ParallelGC collector, 4GB of heap, 3 GB of perm heap, 20 
> virtual CPUs on single KVM guest) which shows strange GC behavior:
> -       immediately after every Full GC run minor GCs are fast (below
> 100ms)
> -       with growing heap occupation minor GC pauses grow to around
> 800ms immediately before every Full GC Find a plot of heap occupation 
> (blue line, left scale) and GC pause duration (grey columns, right 
> scale) attached.
> We use the following GC settings:  
> -Xms4g –Xmx4g –XX:NewSize=800m –XX:MaxNewSize=800m –XX:PermSize=3g – 
> XX:MaxPermSize=3g –XX:TargetSurvivorRatio=50 –XX:SurvivorRatio=8 –
> XX:ParallelGCThreads=20
>  
> I am not sure whether minor GC pauses grow with old gen or perm gen 
> occupation but assume that one of these is the cause.
>
> Perm gen occupation also grows over time because there are 
> (re)generated classes and this would eventually trigger a Full GC if 
> old gen were not filled first.

Which exact version of Java were you using?

> That’s the reason why we configured a rather large perm space.
>
> I can imagine that old gen occupation might cause such a problem if 
> there are many references from old gen to new gen objects.

Yes. Or other sources of roots like code cache (or string table) or others.

> In this case, management of “remembered sets” during new gen 
> collections  could require growing effort when the number of old gen 
> objects grows. Is this correct?

Yes, but it seems that in your case the perm gen (or one of those additional roots) seems to be the problem.

> I have tested G1 for this application and results were worse. As I 
> understand it, management of “remembered sets” is more of a limiting 
> factor with G1 than with ParallelGC, and therefore this seems to 
> corroborate my assumption. Is this correct?

In 7u60 there have been some improvements to remembered set management from code cache. This often decreases the impact of this behavior, but does not remove it. Young GC times will still grow over time.

Can you provide a log with -XX:+PrintGCDetails (with G1)? If you notice ever increasing "Ext Root Scan times", this is the exact problem.

With 8u20, G1 will not need full gc for clearing the "perm gen" any more. It is piggy-backed on concurrent marking.

> Are there any other ideas about the cause of growing minor GC pauses?
> Are there any ideas how to investigate further?
> How to achieve shorter minor GCs without more frequent major GCs?

Use G1 with 8u20+. As mentioned, it can do the necessary cleanup at the end of marking (which impacts that pause time, but it will be significantly faster than a Full GC).

Thanks,
  Thomas