G1垃圾回收器长暂停不知道

我想调整我的应用程序的响应能力，最大允许的GC暂停是40毫秒。无法理解为何这种停顿需要大约900毫秒的时间。应用程序是旨在服务于高QPS的低延迟应用程序。G1垃圾回收器长暂停不知道

GC PARAMS：-Xmx5G -XX：+ UseG1GC -XX：MaxGCPauseMillis = 40

日志：

2014-10-02T16:31:08.508+0530: 2072.186: [GC pause (young) 
Desired survivor size 148373504 bytes, new threshold 15 (max 15) 
- age 1: 10600184 bytes, 10600184 total 
- age 2:  67024 bytes, 10667208 total 
- age 3:  44560 bytes, 10711768 total 
- age 4:  3520 bytes, 10715288 total 
- age 5:  4080 bytes, 10719368 total 
- age 6:  4464 bytes, 10723832 total 
- age 7:  2568 bytes, 10726400 total 
- age 8:  4872 bytes, 10731272 total 
- age 9:  3216 bytes, 10734488 total 
- age 10:  2400 bytes, 10736888 total 
- age 11:  2024 bytes, 10738912 total 
- age 12:  3144 bytes, 10742056 total 
- age 13:  8584 bytes, 10750640 total 
- age 14:  2672 bytes, 10753312 total 
- age 15:  696 bytes, 10754008 total 
, 0.0384210 secs] 
    [Parallel Time: 15.2 ms, GC Workers: 15] 
     [GC Worker Start (ms): Min: 2072186.5, Avg: 2072186.5, Max: 2072186.6, Diff: 0.1] 
     [Ext Root Scanning (ms): Min: 1.0, Avg: 1.0, Max: 1.1, Diff: 0.1, Sum: 15.2] 
     [Update RS (ms): Min: 0.3, Avg: 0.4, Max: 0.4, Diff: 0.1, Sum: 5.7] 
     [Processed Buffers: Min: 1, Avg: 3.3, Max: 5, Diff: 4, Sum: 49] 
     [Scan RS (ms): Min: 0.5, Avg: 0.5, Max: 0.6, Diff: 0.1, Sum: 7.8] 
     [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3] 
     [Object Copy (ms): Min: 12.8, Avg: 12.9, Max: 13.0, Diff: 0.2, Sum: 193.0] 
     [Termination (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.7] 
     [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 1.4] 
     [GC Worker Total (ms): Min: 14.9, Avg: 15.0, Max: 15.1, Diff: 0.2, Sum: 225.1] 
     [GC Worker End (ms): Min: 2072201.5, Avg: 2072201.5, Max: 2072201.6, Diff: 0.1] 
    [Code Root Fixup: 0.2 ms] 
    [Code Root Migration: 0.6 ms] 
    [Clear CT: 0.8 ms] 
    [Other: 21.6 ms] 
     [Choose CSet: 0.0 ms] 
     [Ref Proc: 14.2 ms] 
     [Ref Enq: 0.6 ms] 
     [Free CSet: 6.6 ms] 
    [Eden: 2244.0M(2244.0M)->0.0B(2571.0M) Survivors: 19.0M->10.0M Heap: 2443.7M(5120.0M)->191.4M(5120.0M)] 
[Times: user=0.26 sys=0.00, real=0.90 secs] 
2014-10-02T16:31:09.406+0530: 2073.085: Total time for which application threads were stopped: 0.8992240 seconds

Java的版本：
Java版本 “1.7.0_60”
的Java（ TM）SE运行时环境（内部版本1.7.0_60-b19）
Java HotSpot™64位服务器虚拟机（版本24.60-b09，混合模式）

请帮助我o明白是什么造成了这么长时间的停顿？以及如何预防它？

来源

2014-10-02 Coding Freak

从我所知道的，这个过程在gc期间被阻塞，这意味着它必须等待资源。

这行告诉你的执行时间：

[Times: user=0.26 sys=0.00, real=0.90 secs]

随着

user意味着纯CPU时间。
sys含义内核时间。
real这意味着真实的世界时间。

由java GC messured的时间是低于40毫秒，看到这一行：

, 0.0384210 secs]

这样，就可能出现的块时：

否则IO重操作（例如网络，磁盘）
另一个进程对系统造成高负载的其中一个需要的ressour ces

在你的情况下，我认为肯定有其他东西吃了CPU时间，但很难说。

增加：

可能发生的另一件事是，在GC试图访问一个已经被交换到磁盘造成长期阻塞IO操作内存。我不知道这可能性有多大，所以我可能在这里完全错误。

来源

2014-10-02 13:19:24 snowdragon

感谢您的回答！内存交换是不可能的，我们在机器上有更多的免费ram。我如何确定究竟是什么造成了这种情况？我检查了萨尔值，没有发现有关系 – 2014-10-03 10:51:03

可悲的是我不知道如何进一步缩小它。您可以尝试不同的机器并观察其行为是否有所不同。如果你知道是什么导致了这种行为，我会非常高兴。 – snowdragon 2014-10-06 12:23:53

G1垃圾回收器长暂停不知道

回答

相关问题