Java 堆已满，但所有区域都是空的

Question

我正在尝试调整 G1 GC。应用程序有时会运行一段时间，然后堆会变满，但它显示 Eden、survivor 和 old 区域为 0，并且会调用完整 GC 来释放空间。

我使用的标志: Xmx:30G -XX:+UseG1GC -XX:+AlwaysPreTouch -XX:+UseStringDeduplication -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+ExplicitGCInvokesConcurrent -XX:+ParallelRefProcEnabled -XX:MaxGCPauseMillis=200 -XX:ParallelGCThreads=12 -XX:ConcGCThreads=4

GC 日志:

    {Heap before GC invocations=629 (full 0):
 garbage-first heap   total 31457280K, used 31434556K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41962K, capacity 42424K, committed 42956K, reserved 1087488K
  class space    used 4589K, capacity 4749K, committed 4812K, reserved 1048576K
2017-12-07T14:47:41.979+0000: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 18116.906: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 48.13 ms, remaining time: 151.87 ms, target pause time: 200.00 ms]
 18116.906: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 0 regions, survivors: 0 regions, predicted young region time: 0.00 ms]
 18116.906: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 0 regions, survivors: 0 regions, old: 0 regions, predicted pause time: 48.13 ms, target pause time: 200.00 ms]
2017-12-07T14:47:41.981+0000: [SoftReference, 0 refs, 0.0004177 secs]2017-12-07T14:47:41.981+0000: [WeakReference, 0 refs, 0.0002174 secs]2017-12-07T14:47:41.981+0000: [FinalReference, 0 refs, 0.0003298 secs]2017-12-07T14:47:41.982+0000: [PhantomReference, 0 refs, 0 refs, 0.0004635 secs]2017-12-07T14:47:41.982+0000: [JNI Weak Reference, 0.0000152 secs], 0.0439856 secs]
   [Parallel Time: 1.4 ms, GC Workers: 12]
      [GC Worker Start (ms): Min: 18116906.3, Avg: 18116906.3, Max: 18116906.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.5, Avg: 0.6, Max: 0.9, Diff: 0.4, Sum: 6.9]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Processed Buffers: Min: 0, Avg: 0.1, Max: 1, Diff: 1, Sum: 1]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 0.6, Max: 0.7, Diff: 0.7, Sum: 6.8]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 12]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 1.2, Avg: 1.2, Max: 1.3, Diff: 0.1, Sum: 15.0]
      [GC Worker End (ms): Min: 18116907.6, Avg: 18116907.6, Max: 18116907.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [String Dedup Fixup: 39.9 ms, GC Workers: 12]
      [Queue Fixup (ms): Min: 0.0, Avg: 11.3, Max: 18.1, Diff: 18.1, Sum: 135.1]
      [Table Fixup (ms): Min: 21.7, Avg: 27.8, Max: 35.2, Diff: 13.5, Sum: 333.3]
   [Clear CT: 0.1 ms]
   [Other: 2.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.6 ms]
      [Ref Enq: 0.1 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 30.0G(30.0G)->30.0G(30.0G)]
Heap after GC invocations=630 (full 0):
 garbage-first heap   total 31457280K, used 31434556K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41962K, capacity 42424K, committed 42956K, reserved 1087488K
  class space    used 4589K, capacity 4749K, committed 4812K, reserved 1048576K
}
 [Times: user=0.49 sys=0.01, real=0.05 secs] 
{Heap before GC invocations=630 (full 0):
 garbage-first heap   total 31457280K, used 31434556K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41962K, capacity 42424K, committed 42956K, reserved 1087488K
  class space    used 4589K, capacity 4749K, committed 4812K, reserved 1048576K
2017-12-07T14:47:42.024+0000: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 18116.952: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 47.06 ms, remaining time: 152.94 ms, target pause time: 200.00 ms]
 18116.952: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 0 regions, survivors: 0 regions, predicted young region time: 0.00 ms]
 18116.952: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 0 regions, survivors: 0 regions, old: 0 regions, predicted pause time: 47.06 ms, target pause time: 200.00 ms]
2017-12-07T14:47:42.026+0000: [SoftReference, 0 refs, 0.0003988 secs]2017-12-07T14:47:42.027+0000: [WeakReference, 0 refs, 0.0003844 secs]2017-12-07T14:47:42.027+0000: [FinalReference, 0 refs, 0.0002286 secs]2017-12-07T14:47:42.027+0000: [PhantomReference, 0 refs, 0 refs, 0.0004361 secs]2017-12-07T14:47:42.028+0000: [JNI Weak Reference, 0.0000169 secs], 0.0433898 secs]
   [Parallel Time: 1.5 ms, GC Workers: 12]
      [GC Worker Start (ms): Min: 18116952.0, Avg: 18116952.1, Max: 18116952.1, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.7, Avg: 0.8, Max: 0.9, Diff: 0.1, Sum: 9.5]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.2]
         [Processed Buffers: Min: 0, Avg: 0.1, Max: 1, Diff: 1, Sum: 1]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Termination (ms): Min: 0.0, Avg: 0.4, Max: 0.5, Diff: 0.5, Sum: 5.3]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 12]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 1.3, Avg: 1.3, Max: 1.4, Diff: 0.1, Sum: 16.1]
      [GC Worker End (ms): Min: 18116953.4, Avg: 18116953.4, Max: 18116953.4, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [String Dedup Fixup: 39.2 ms, GC Workers: 12]
      [Queue Fixup (ms): Min: 0.0, Avg: 11.4, Max: 15.4, Diff: 15.4, Sum: 136.9]
      [Table Fixup (ms): Min: 23.7, Avg: 27.7, Max: 39.1, Diff: 15.4, Sum: 332.3]
   [Clear CT: 0.1 ms]
   [Other: 2.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.6 ms]
      [Ref Enq: 0.1 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 30.0G(30.0G)->30.0G(30.0G)]
Heap after GC invocations=631 (full 0):
 garbage-first heap   total 31457280K, used 31434556K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41962K, capacity 42424K, committed 42956K, reserved 1087488K
  class space    used 4589K, capacity 4749K, committed 4812K, reserved 1048576K
}
 [Times: user=0.49 sys=0.00, real=0.04 secs] 
 18116.996: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: allocation request failed, allocation request: 16 bytes]
 18116.997: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 8388608 bytes, attempted expansion amount: 8388608 bytes]
 18116.997: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap already fully expanded]
{Heap before GC invocations=631 (full 0):
 garbage-first heap   total 31457280K, used 31434556K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41962K, capacity 42424K, committed 42956K, reserved 1087488K
  class space    used 4589K, capacity 4749K, committed 4812K, reserved 1048576K
2017-12-07T14:47:42.069+0000: [Full GC (Allocation Failure) 2017-12-07T14:48:06.386+0000: [SoftReference, 122 refs, 0.0001069 secs]2017-12-07T14:48:06.386+0000: [WeakReference, 22631 refs, 0.0079235 secs]2017-12-07T14:48:06.394+0000: [FinalReference, 395 refs, 0.0005771 secs]2017-12-07T14:48:06.394+0000: [PhantomReference, 0 refs, 0 refs, 0.0000163 secs]2017-12-07T14:48:06.394+0000: [JNI Weak Reference, 0.0000357 secs] 29G->14G(30G), 53.8180666 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 30.0G(30.0G)->14.4G(30.0G)], [Metaspace: 41962K->41951K(1087488K)]
Heap after GC invocations=632 (full 1):
 garbage-first heap   total 31457280K, used 15144510K [0x0000000080000000, 0x0000000080807800, 0x0000000800000000)
  region size 8192K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 41951K, capacity 42406K, committed 42956K, reserved 1087488K
  class space    used 4587K, capacity 4746K, committed 4812K, reserved 1048576K
}

请帮我找出问题所在以及如何避免完全GC。

Answer 1

这可能是OpenJDK bug 8165150 ，这意味着您在 Full GC 之前正在经历 noop young gen 回收。这不是最理想的，但只要发生完整 GC 并且可以释放 JVM 应该恢复的内存。

您可以通过确保堆中有足够的可用空间来避免此问题，确保您的应用程序不会泄漏，并在填满之前启动并发周期，例如通过调整 IHOP。

Full GC 之后的生命集大小仅为 14GiB，因此 60% 左右的 IHOP 可能会有所帮助。