java - 没有疏散失败，但 G1GC 中仍然发生 Full GC

Question

我正在调整 G1GC 以避免发生 FullGC。 通过遵循此提示 http://www.infoq.com/articles/tuning-tips-G1-GC ，我没有看到任何类似“to-space exused”的日志。

Java HotSpot(TM) 64-Bit Server VM (24.76-b04) for linux-amd64 JRE (1.7.0_76-b13), built on Dec 18 2014 16:58:39 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 32934888k(13890072k free), swap 48197628k(48197628k free)
CommandLine flags: 
-XX:AutoBoxCacheMax=3000000 -XX:ConcGCThreads=4 -XX:+DisableExplicitGC -XX:G1ReservePercent=25 -XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=11811160064 -XX:MaxDirectMemorySize=1073741824 -XX:MaxGCPauseMillis=1000 -XX:MaxHeapSize=11811160064 -XX:-OmitStackTraceInFastThrow 
-XX:ParallelGCThreads=8 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 
-XX:+PrintTenuringDistribution -XX:+UseCompressedOops -XX:+UseG1GC

出于哪些其他原因，GC 会决定执行完整收集？ 或者仍然存在疏散失败但日志未启用？

70861.400: [GC pause (mixed)
Desired survivor size 37748736 bytes, new threshold 1 (max 15)
- age   1:   49450208 bytes,   49450208 total
- age   2:    3236616 bytes,   52686824 total
- age   3:   10086240 bytes,   62773064 total
- age   4:     188936 bytes,   62962000 total
- age   5:     816536 bytes,   63778536 total
- age   6:    1024560 bytes,   64803096 total
- age   7:    1341640 bytes,   66144736 total
- age   8:    1562648 bytes,   67707384 total
- age   9:      59200 bytes,   67766584 total
, 0.2471520 secs]
[Parallel Time: 225.0 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 70861401.2, Avg: 70861401.4, Max: 70861401.7, Diff: 0.6]
    [Ext Root Scanning (ms): Min: 3.8, Avg: 4.1, Max: 4.5, Diff: 0.6, Sum: 33.0]
      [Update RS (ms): Min: 93.2, Avg: 93.4, Max: 93.5, Diff: 0.3, Sum: 746.9]
         [Processed Buffers: Min: 92, Avg: 108.0, Max: 124, Diff: 32, Sum: 864]
      [Scan RS (ms): Min: 29.7, Avg: 29.7, Max: 29.8, Diff: 0.1, Sum: 238.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 95.9, Avg: 96.2, Max: 97.0, Diff: 1.1, Sum: 769.6]
      [Termination (ms): Min: 0.0, Avg: 0.8, Max: 1.0, Diff: 1.0, Sum: 6.4]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.2, Sum: 0.7]
      [GC Worker Total (ms): Min: 224.1, Avg: 224.3, Max: 224.6, Diff: 0.6, Sum: 1794.6]
      [GC Worker End (ms): Min: 70861625.7, Avg: 70861625.7, Max: 70861625.9, Diff: 0.2]
   [Code Root Fixup: 0.2 ms]
   [Code Root Migration: 0.1 ms]
   [Clear CT: 4.8 ms]
   [Other: 17.2 ms]
      [Choose CSet: 0.4 ms]
      [Ref Proc: 7.5 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.0 ms]
   [Eden: 488.0M(488.0M)->0.0B(2956.0M) Survivors: 72.0M->20.0M Heap: 5882.4M(11.0G)->5394.1M(11.0G)]


71319.172: [GC pause (young) (initial-mark)
Desired survivor size 195035136 bytes, new threshold 15 (max 15)
- age   1:    3965480 bytes,    3965480 total
, 0.2243330 secs]
   [Parallel Time: 182.7 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 71319173.4, Avg: 71319173.6, Max: 71319174.0, Diff: 0.6]
      [Ext Root Scanning (ms): Min: 3.4, Avg: 4.0, Max: 4.4, Diff: 1.0, Sum: 31.8]
      [Code Root Marking (ms): Min: 2.0, Avg: 2.7, Max: 6.0, Diff: 4.0, Sum: 21.4]
      [Update RS (ms): Min: 105.7, Avg: 109.2, Max: 110.6, Diff: 4.9, Sum: 873.2]
         [Processed Buffers: Min: 115, Avg: 127.6, Max: 142, Diff: 27, Sum: 1021]
      [Scan RS (ms): Min: 11.7, Avg: 12.6, Max: 12.9, Diff: 1.1, Sum: 100.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Object Copy (ms): Min: 52.2, Avg: 52.7, Max: 52.9, Diff: 0.7, Sum: 421.2]
      [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.2, Max: 0.6, Diff: 0.6, Sum: 1.9]
      [GC Worker Total (ms): Min: 181.0, Avg: 181.3, Max: 181.6, Diff: 0.6, Sum: 1450.7]
      [GC Worker End (ms): Min: 71319354.8, Avg: 71319355.0, Max: 71319355.3, Diff: 0.6]
   [Code Root Fixup: 0.3 ms]
   [Code Root Migration: 0.2 ms]
   [Clear CT: 3.6 ms]
   [Other: 37.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 29.8 ms]
      [Ref Enq: 0.5 ms]
      [Free CSet: 2.3 ms]
   [Eden: 2332.0M(2956.0M)->0.0B(2872.0M) Survivors: 20.0M->72.0M Heap: 7725.6M(11.0G)->5448.0M(11.0G)]
 [Times: user=1.51 sys=0.00, real=0.22 secs]
71319.397: [GC concurrent-root-region-scan-start]
71319.468: [GC concurrent-root-region-scan-end, 0.0707700 secs]
71319.468: [GC concurrent-mark-start]
71320.512: [GC pause (young)
Desired survivor size 192937984 bytes, new threshold 15 (max 15)
- age   1:   57002072 bytes,   57002072 total
- age   2:    3685360 bytes,   60687432 total
, 0.1300980 secs]
   [Parallel Time: 122.5 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 71320513.1, Avg: 71320513.3, Max: 71320513.8, Diff: 0.7]
      [Ext Root Scanning (ms): Min: 3.5, Avg: 4.0, Max: 4.3, Diff: 0.8, Sum: 32.4]
      [SATB Filtering (ms): Min: 0.0, Avg: 0.1, Max: 0.8, Diff: 0.8, Sum: 0.8]
      [Update RS (ms): Min: 75.2, Avg: 75.7, Max: 76.0, Diff: 0.8, Sum: 605.8]
         [Processed Buffers: Min: 169, Avg: 183.8, Max: 202, Diff: 33, Sum: 1470]
      [Scan RS (ms): Min: 2.9, Avg: 2.9, Max: 3.0, Diff: 0.1, Sum: 23.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 38.7, Avg: 38.8, Max: 38.9, Diff: 0.1, Sum: 310.4]
      [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.1, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [GC Worker Total (ms): Min: 121.2, Avg: 121.7, Max: 121.9, Diff: 0.7, Sum: 973.3]
      [GC Worker End (ms): Min: 71320635.0, Avg: 71320635.0, Max: 71320635.0, Diff: 0.0]
   [Code Root Fixup: 0.2 ms]
   [Code Root Migration: 0.0 ms]
   [Clear CT: 1.4 ms]
   [Other: 6.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.7 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 0.5 ms]
   [Eden: 260.0M(2872.0M)->0.0B(2736.0M) Survivors: 72.0M->68.0M Heap: 5828.3M(11.0G)->5562.4M(11.0G)]
 [Times: user=0.98 sys=0.00, real=0.12 secs]


71320.645: [Full GC 5562M->3567M(11G), 23.7159350 secs]
   [Eden: 0.0B(2736.0M)->0.0B(4804.0M) Survivors: 68.0M->0.0B Heap: 5562.4M(11.0G)->3567.2M(11.0G)], [Perm: 34637K->34637K(36864K)]
 [Times: user=38.34 sys=0.02, real=23.72 secs]

71344.362: [GC concurrent-mark-abort]
71436.544: [GC pause (young)
Desired survivor size 316669952 bytes, new threshold 15 (max 15)
- age   1:     448512 bytes,     448512 total
- age   2:   55511136 bytes,   55959648 total
- age   3:    3685280 bytes,   59644928 total
, 0.2012910 secs]
   [Parallel Time: 183.5 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 71436545.9, Avg: 71436546.2, Max: 71436546.6, Diff: 0.7]
      [Ext Root Scanning (ms): Min: 5.2, Avg: 5.4, Max: 5.9, Diff: 0.7, Sum: 43.3]
      [Update RS (ms): Min: 44.0, Avg: 45.8, Max: 52.6, Diff: 8.6, Sum: 366.0]
         [Processed Buffers: Min: 118, Avg: 128.2, Max: 136, Diff: 18, Sum: 1026]
      [Scan RS (ms): Min: 5.2, Avg: 11.8, Max: 13.5, Diff: 8.3, Sum: 94.4]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [Object Copy (ms): Min: 118.8, Avg: 118.9, Max: 119.1, Diff: 0.3, Sum: 951.4]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.3, Max: 0.5, Diff: 0.5, Sum: 2.3]
      [GC Worker Total (ms): Min: 181.9, Avg: 182.3, Max: 182.6, Diff: 0.7, Sum: 1458.3]
      [GC Worker End (ms): Min: 71436728.2, Avg: 71436728.5, Max: 71436728.7, Diff: 0.5]
   [Code Root Fixup: 0.2 ms]
   [Code Root Migration: 0.3 ms]
   [Clear CT: 4.2 ms]
   [Other: 13.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 6.6 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 3.6 ms]
   [Eden: 4804.0M(4804.0M)->0.0B(3412.0M) Survivors: 0.0B->152.0M Heap: 9208.4M(11.0G)->4554.4M(11.0G)]
 [Times: user=1.50 sys=0.00, real=0.20 secs]

它在 71320.645 启动了 FullGC，但看起来没有发生疏散失败，有什么想法吗？

Answer 1

在 java 7 上运行 G1GC 可能不是一个好主意。当时它有很多有问题的行为。其中类卸载需要一次full GC，this has been fixed with jdk8u40

更不用说 GC 日志在 8 中提供了更多有用的信息。

其他原因也是可以想象的，例如巨大的对象分配需要比可用区域更多的连续空闲区域。 8 的日志可能会更有用。

编辑:实际上，该功能可能位于 7u45 中的标志后面，请尝试 -XX:+PrintGCCause