我有一个在 Hotspot JVM 上的 Java 7 update 45 上运行的应用程序。我正在尝试调整参数以适用于低延迟应用程序,以下是我为此运行设置的 JVM 参数。GC 日志中各个步骤的时间(大约 25 毫秒)不等于暂停时间(>600 毫秒)。我怎么知道是什么导致这个暂停时间如此之长?在大多数集合中,它们加起来很好,并且符合暂停时间目标。我偶尔会看到如此大的停顿,大约在 15-20 分钟内停顿一次(虽然不那么规律)。
-server -Xmx2g -Xms2g -XX:PermSize=128m -XX:MaxPermSize=128m -XX:+UseG1GC -XX:MaxGCPauseMillis=30 -XX:ParallelGCThreads=9 -XX:ConcGCThreads=4 -XX:G1HeapRegionSize=4M -XX: InitiatingHeapOccupancyPercent=45 -XX:+PrintTLAB -XX:+AggressiveOpts -Xloggc:/integral/logs/gc.log -verbose:gc -XX:+PrintTenuringDistribution -XX:+PrintGCDateStamps -XX:+PrintAdaptiveSizePolicy -XX:+PrintGCDetails -XX :+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=3026 -Dcom.sun.management.jmxremote.local。只有=假-Dcom.sun.management.jmxremote.authenticate=假-Dcom.sun.management.jmxremote.ssl=假"
2014-01-28T16:16:12.084+0000: 27507.054: Application time: 8.9506630 seconds
2014-01-28T16:16:12.084+0000: 27507.055: [GC pause (young)
Desired survivor size 81788928 bytes, new threshold 15 (max 15)
- age 1: 2299088 bytes, 2299088 total
- age 2: 1732832 bytes, 4031920 total
- age 3: 1748064 bytes, 5779984 total
- age 4: 1709368 bytes, 7489352 total
- age 5: 1732360 bytes, 9221712 total
- age 6: 1722776 bytes, 10944488 total
- age 7: 1712168 bytes, 12656656 total
- age 8: 1706240 bytes, 14362896 total
- age 9: 1692040 bytes, 16054936 total
- age 10: 1736008 bytes, 17790944 total
- age 11: 1566384 bytes, 19357328 total
- age 12: 1508456 bytes, 20865784 total
- age 13: 1491480 bytes, 22357264 total
- age 14: 1652136 bytes, 24009400 total
- age 15: 1502120 bytes, 25511520 total
27507.055: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 12464, predicted base time: 7.97 ms, remaining time: 22.03 ms, target pause time: 30.00 ms]
27507.055: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 298 regions, survivors: 9 regions, predicted young region time: 12.39 ms]
27507.055: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 298 regions, survivors: 9 regions, old: 0 regions, predicted pause time: 20.36 ms, target pause time: 30.00 ms]
, 0.0236600 secs]
[Parallel Time: 22.0 ms, GC Workers: 9]
[GC Worker Start (ms): Min: 27507055.7, Avg: 27507057.0, Max: 27507058.7, Diff: 3.1]
[Ext Root Scanning (ms): Min: 2.1, Avg: 3.8, Max: 5.2, Diff: 3.1, Sum: 34.4]
[Update RS (ms): Min: 1.9, Avg: 2.3, Max: 3.0, Diff: 1.1, Sum: 20.8]
[Processed Buffers: Min: 4, Avg: 11.7, Max: 23, Diff: 19, Sum: 105]
[Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 1.2]
[Object Copy (ms): Min: 12.9, Avg: 13.1, Max: 13.3, Diff: 0.3, Sum: 117.6]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.5, Max: 0.8, Diff: 0.8, Sum: 4.8]
[GC Worker Total (ms): Min: 17.7, Avg: 19.9, Max: 21.5, Diff: 3.8, Sum: 178.8]
[GC Worker End (ms): Min: 27507076.4, Avg: 27507076.9, Max: 27507077.2, Diff: 0.8]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 1.3 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.6 ms]
[Eden: 1192.0M(1192.0M)->0.0B(1192.0M) Survivors: 36.0M->36.0M Heap: 1796.8M(2048.0M)->605.0M(2048.0M)]
[Times: user=0.17 sys=0.00, real=0.64 secs]
2014-01-28T16:16:12.719+0000: 27507.690: Total time for which application threads were stopped: 0.6354760 seconds