java g1 cpu 100_垃圾收集 – 为什么Java G1 gc花费这么多时间扫描RS？

我目前正在评估G1垃圾收集器以及它如何为我们的应用程序执行.看一下gc-log,我注意到很多集合都有很长的“扫描RS”阶段：

7968.869: [GC pause (mixed), 10.27831700 secs]

[Parallel Time: 10080.8 ms]

(...)

[Scan RS (ms): 4030.4 4034.1 4032.0 4032.0

Avg: 4032.1, Min: 4030.4, Max: 4034.1, Diff: 3.7]

[Object Copy (ms): 6038.5 6033.3 6036.7 6037.1

Avg: 6036.4, Min: 6033.3, Max: 6038.5, Diff: 5.2]

(...)

[Eden: 19680M(19680M)->0B(20512M) Survivors: 2688M->2624M Heap:

75331M(111904M)->51633M(115744M)]

[Times: user=40.49 sys=0.02, real=10.28 secs]

所有删除的日志行条目都以单位数ms显示运行时.

我想大部分时间都应该花在复制上,对吧？ Scan RS需要这么长时间的原因是什么？关于如何调整G1设置的任何想法？

JVM开始于

-Xms40960M -Xmx128G -XX:+UseG1GC -verbose:gc -XX:+PrintGCDetails -Xloggc:gc.log

编辑：哦,我忘了……我正在使用Java 7u25

更新：

我注意到另外两件奇怪的事情：

正在执行并行运行时,并发GC运行正在继续.我不确定这是否有意,但对我来说似乎有点不对劲.不可否认,这是一个极端的例子,但我确实在我的日志中看到了这种行为.

另一件事是我的JVM进程增长到160克.考虑到128g的堆大小,这是一个相当大的开销.这是预期的,还是G1泄漏记忆？关于如何找到它的任何想法？

PS：我不确定我是否应该为更新提出新的问题……如果你们中有人认为这会有所帮助,请告诉我;)

更新2：

我猜G1真的可能会泄漏内存：http://printfdebugger.tumblr.com/post/19142660766/how-i-learned-to-love-cms-and-had-my-heart-broken-by-g1

由于这是目前的交易破坏者,我不会花更多的时间来玩这个.

我还没有尝试的是配置区域大小(-XX：G1HeapRegionSize)和降低堆占用率(-XX：InitiatingHeapOccupancyPercent).16187.740: [GC concurrent-mark-start]

16203.934: [GC pause (young), 2.89871800 secs]

(...)

16218.455: [GC pause (young), 4.61375100 secs]

(...)

16237.441: [GC pause (young), 4.46131800 secs]

(...)

16257.785: [GC pause (young), 4.73922600 secs]

(...)

16275.417: [GC pause (young), 3.87863400 secs]

(...)

16291.505: [GC pause (young), 3.72626400 secs]

(...)

16307.824: [GC pause (young), 3.72921700 secs]

(...)

16325.851: [GC pause (young), 3.91060700 secs]

(...)

16354.600: [GC pause (young), 5.6137968.869: [GC pause (mixed), 10.27831700 secs]

[Parallel Time: 10080.8 ms]

(...)

[Scan RS (ms): 4030.4 4034.1 4032.0 4032.0

Avg: 4032.1, Min: 4030.4, Max: 4034.1, Diff: 3.7]

[Object Copy (ms): 6038.5 6033.3 6036.7 6037.1

Avg: 6036.4, Min: 6033.3, Max: 6038.5, Diff: 5.2]

(...)

[Eden: 19680M(19680M)->0B(20512M) Survivors: 2688M->2624M Heap:

75331M(111904M)->51633M(115744M)]

[Times: user=40.49 sys=0.02, real=10.28 secs]7968.869: [GC pause (mixed), 10.27831700 secs]

[Parallel Time: 10080.8 ms]

(...)

[Scan RS (ms): 4030.4 4034.1 4032.0 4032.0

Avg: 4032.1, Min: 4030.4, Max: 4034.1, Diff: 3.7]

[Object Copy (ms): 6038.5 6033.3 6036.7 6037.1

Avg: 6036.4, Min: 6033.3, Max: 6038.5, Diff: 5.2]

(...)

[Eden: 19680M(19680M)->0B(20512M) Survivors: 2688M->2624M Heap:

75331M(111904M)->51633M(115744M)]

[Times: user=40.49 sys=0.02, real=10.28 secs]secs]

(...)

16393.069: [GC pause (young), 17.50453200 secs]

(...)

16414.590: [GC concurrent-mark-end, 226.8497670 sec]