G1 feedback: frantic GC cycles

[Igor Veresov]

This is pretty weird. Simone, could you run it with -XX:+PrintHeapAtGC, 
it would be nice to see how big the survivor spaces are. It seems like 
at the time a collection happens there is only one young region.

igor

On 4/29/11 10:59 AM, Simone Bordet wrote:
> Hi,
>
> I am running with JDK 7:
>
> java version "1.7.0-ea"
> Java(TM) SE Runtime Environment (build 1.7.0-ea-b139)
> Java HotSpot(TM) 64-Bit Server VM (build 21.0-b09, mixed mode)
>
> The application is IntelliJ IDEA, and I am using these command lines options:
>
> -Xms1024m
> -Xmx1024m
> -Xmn512m
> -XX:MaxPermSize=256m
> -ea
> -verbose:gc
> -XX:+PrintGCDetails
> -XX:+DisableExplicitGC
> -XX:+PrintGCDateStamps
> -XX:+UnlockExperimentalVMOptions
> -XX:+UseG1GC
> -XX:+TieredCompilation
> -XX:+PrintCommandLineFlags
> -XX:+AggressiveOpts
>
> The application works well, I use it heavily for coding, and G1 works
> well: small pauses (which is what I like when I have keyboard-based
> mind-less automatisms) and stable.
>
> However, from time to time, say 2-3 times a day, I experience a few
> seconds of frantic GC cycles from G1, for which I have attached a log.
> The log starts at 18:44:10 (previous logging was fine and I hope not
> relevant), and the frantic cycles start at 19:14:08 (around line 4741
> of the log) and lasts roughly 20 seconds.
> During these 20 seconds, the application was unresponsive (that is
> what allowed me to detect these frantic GC cycles) so I stopped
> working on it to look at the GC logs and waited until the GC came back
> to normal activity (i.e. the frantic cycles stopped).
>
> After those 20 seconds, G1 seems to be able to go back to normal
> activity and the application works again well.
> During those 20 seconds, there has been roughly one collection every
> 100 ms or so.
>
> It is entirely possible that the application is leaking (I'm just a
> user, not a developer of the application).
> I was wondering if someone saw this before ?
>
>> From the logs and jconsole, it seems that the old generation is quite
> full (jconsole reported 540 M occupied) , but I still have ~512 M
> available of young generation available (and jconsole confirms that a
> young GC brings the new generation to 6 M or less).
>
> Other than using G1 for the IDE, I often consult on GC tuning, so any
> additional information or improvement to G1 is good news for me, and
> understanding this behavior will help on suggesting G1 to customers or
> tuning G1 better.
>
> I am pretty sure I saw the same anomaly (frantic cycles) with G1 on
> JDK 6 as well (1.6.0_24), so it seems more a G1 behavior than JDK's.
>
> I can fairly easily reproduce the problem on a daily basis, so any
> suggestion to track down this issue is welcome (like additional
> command line switches, or confirmation that it happens with JDK 6 as
> well, etc.)
>
> Thanks !
>
> Simon