regarding long young generation pause when using G1 GC

[Yu Zhang]

Amit,

Which jdk version are you using?

You give MaxGCPauseMillis=500, but it seems g1 is adjusting eden size 
too big, up to 13g. I am curious why. Can you add a flag 
-XX:+PrintAdaptiveSizePolicy? Meanwhile, to reduce young gc pause, can 
you try to a smaller number for MaxGCPauseMillis, or give a smaller eden 
size?

Another thing I noticed, whenever you have long gc pause, the system cpu 
is high. Maybe the system is busy doing something else?

Thanks,
Jenny

On 1/21/2016 4:30 AM, Amit Mishra wrote:
>
> Hello team,
>
> Please help me with G1 GC long young generation pause..
>
> At one of our Customer deployment we were using CMS with 48G heap size 
> and facing Concurrent mode failure every month.
>
> To solve this we started load test using G1 GC on lab but we are 
> seeing intermittent long GC pause as long as 148 seconds,
>
> Could you please look into logs and confirm what best we can do to 
> ascertain root cause and possible tuning to fix this.
>
> Thanks for help in advance.
>
> We are using default GC parameters:(Attaching full GC file as well)
>
> JVM_ARGS="${JVM_ARGS} -XX:-OmitStackTraceInFastThrow"
>
> JVM_ARGS="${JVM_ARGS} -XX:-UseSSE42Intrinsics"
>
> JVM_ARGS="${JVM_ARGS} -XX:-ReduceInitialCardMarks"
>
> JVM_ARGS="${JVM_ARGS} -XX:+UseG1GC"
>
> JVM_ARGS="${JVM_ARGS} -XX:MaxGCPauseMillis=500"
>
> JVM_ARGS="${JVM_ARGS} -XX:+UseCompressedOops"
>
> JVM_ARGS="${JVM_ARGS} -XX:+PrintFlagsFinal"
>
> JVM_ARGS="${JVM_ARGS} -XX:-EliminateLocks"
>
> JVM_ARGS="${JVM_ARGS} -XX:+UseLargePages"
>
> export GC_LOG="${PROJECT_HOME}/log/gcstats.log.$$"
>
> JVM_ARGS=$JVM_ARGS" -Xloggc:${GC_LOG}"
>
> JVM_ARGS=$JVM_ARGS" -verbose:gc"
>
> JVM_ARGS="${JVM_ARGS} -XX:+DisableExplicitGC"
>
> JVM_ARGS=$JVM_ARGS" -XX:+AggressiveOpts"
>
> JVM_ARGS="${JVM_ARGS} -XX:+HeapDumpOnOutOfMemoryError"
>
> JVM_ARGS="${JVM_ARGS} -XX:ReservedCodeCacheSize=128m"
>
> JVM_ARGS="${JVM_ARGS} -XX:PermSize=256m"
>
> JVM_ARGS="${JVM_ARGS} -XX:MaxPermSize=256m"
>
> JVM_ARGS="${JVM_ARGS} -Xmx28672m"
>
> JVM_ARGS="${JVM_ARGS} -Xms28672m
>
> Long GC pause.
>
> 5020.853: [GC pause (young), 148.0343389 secs]
>
>    [Parallel Time: 142474.3 ms, GC Workers: 13]
>
>       [GC Worker Start (ms): Min: 5022695.7, Avg: 5022705.6, Max: 
> 5022714.4, Diff: 18.7]
>
>       [Ext Root Scanning (ms): Min: 143.0, Avg: 2550.5, Max: 6442.5, 
> Diff: 6299.4, Sum: 33157.1]
>
>       [Update RS (ms): Min: 5704.6, Avg: 19017.1, Max: 45977.9, Diff: 
> 40273.3, Sum: 247222.7]
>
>          [Processed Buffers: Min: 0, Avg: 26.9, Max: 291, Diff: 291, 
> Sum: 350]
>
>       [Scan RS (ms): Min: 70538.2, Avg: 92539.7, Max: 114688.0, Diff: 
> 44149.8, Sum: 1203016.2]
>
>       [Object Copy (ms): Min: 894.7, Avg: 9265.9, Max: 20674.1, Diff: 
> 19779.4, Sum: 120456.9]
>
>       [Termination (ms): Min: 10169.3, Avg: 19073.0, Max: 26684.1, 
> Diff: 16514.7, Sum: 247949.3]
>
>       [GC Worker Other (ms): Min: 0.1, Avg: 4.5, Max: 18.2, Diff: 
> 18.0, Sum: 58.4]
>
>       [GC Worker Total (ms): Min: 142441.2, Avg: 142450.8, Max: 
> 142461.1, Diff: 19.8, Sum: 1851860.7]
>
>       [GC Worker End (ms): Min: 5165155.6, Avg: 5165156.4, Max: 
> 5165162.0, Diff: 6.4]
>
>    [Code Root Fixup: 2.2 ms]
>
>    [Clear CT: 11.2 ms]
>
>    [Other: 5546.7 ms]
>
>       [Choose CSet: 0.0 ms]
>
>       [Ref Proc: 47.4 ms]
>
>       [Ref Enq: 0.9 ms]
>
>       [Free CSet: 3642.1 ms]
>
>    [Eden: 13.2G(13.2G)->0.0B(1416.0M) Survivors: 16.0M->16.0M Heap: 
> 24.7G(28.0G)->11.5G(28.0G)]
>
>  [Times: user=184.95 sys=34.49, real=148.07 secs]
>
>
> Thanks,
>
> Amit
>
>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20160121/676df83c/attachment.html>