Received the following report from the performance team and it is hampering their tuning efforts.

In the G1 logs, the information printed for the pause following a full GC is misleading.

Here's an example from Jenny Zhang:

JDK version:
java(TM) SE Runtime Environment (build 1.8.0-ea-b78)
Java HotSpot(TM) 64-Bit Server VM (build 25.0-b19, mixed mode)

OS: Linux x64
Linux sc14ia05 2.6.39-200.24.1.el6uek.x86_64 #1 SMP Sat Jun 23 02:39:07 EDT 2012 x86_64 x86_64 x86_64 GNU/Linux

In the gc log, sometimes I see lines like:
 [Eden: 2368.0M(1840.0M)->0.0B(1632.0M) Survivors: 0.0B->304.0M Heap: 20.7G(36.0G)->20.2G(36.0G)]

The used is larger than the capacity of the Eden.

Lines before this:
411.322: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 519 regions, reclaimable: 3980609520 bytes (10.30 %), threshold: 10.00 %]
 (to-space exhausted), 0.4279260 secs]
   [Parallel Time: 391.9 ms, GC Workers: 18]
      [GC Worker Start (ms): Min: 410894.1, Avg: 410894.5, Max: 410894.9, Diff: 0.8]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 1.2, Diff: 1.2, Sum: 3.3]
      [Update RS (ms): Min: 21.7, Avg: 22.5, Max: 22.9, Diff: 1.2, Sum: 405.0]
         [Processed Buffers: Min: 54, Avg: 78.1, Max: 98, Diff: 44, Sum: 1405]
      [Scan RS (ms): Min: 6.5, Avg: 6.5, Max: 6.6, Diff: 0.1, Sum: 117.6]
      [Object Copy (ms): Min: 361.6, Avg: 361.7, Max: 361.8, Diff: 0.3, Sum: 6511.0]
      [Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 3.0]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
      [GC Worker Total (ms): Min: 390.8, Avg: 391.1, Max: 391.5, Diff: 0.8, Sum: 7040.2]
      [GC Worker End (ms): Min: 411285.6, Avg: 411285.6, Max: 411285.7, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 2.9 ms]
   [Other: 33.1 ms]
      [Choose CSet: 0.3 ms]
      [Ref Proc: 0.6 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 0.3 ms]
   [Eden: 0.0B(1840.0M)->0.0B(1840.0M) Survivors: 0.0B->0.0B Heap: 36.0G(36.0G)->36.0G(36.0G)]
 [Times: user=1.13 sys=0.10, real=0.43 secs]
 411.335: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: allocation request failed, allocation request: 56 bytes]
 411.335: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 16777216 bytes, attempted expansion amount: 16777216 bytes]
 411.335: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
411.336: [Full GC (Allocation Failure) 35G->18G(36G), 8.0471890 secs]
 [Times: user=8.50 sys=0.01, real=8.05 secs]
433.639: [GC pause (G1 Evacuation Pause) (young) 433.640: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 26203, predicted base time: 13.50 ms, remaining time: 186.50 ms, target pause time: 200.00 ms]
 433.640: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 148 regions, survivors: 0 regions, predicted young region time: 164.22 ms]
 433.640: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 148 regions, survivors: 0 regions, old: 0 regions, predicted pause time: 177.72 ms, target pause time: 200.00 ms]
 433.895: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: occupancy higher than threshold, occupancy: 21458059264 bytes, allocation request: 0 bytes, threshold: 17394617520 bytes (45.00 %), source: end of GC]
, 0.2552910 secs]
   [Parallel Time: 251.1 ms, GC Workers: 18]
      [GC Worker Start (ms): Min: 433640.7, Avg: 433640.9, Max: 433641.1, Diff: 0.5]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 1.0, Diff: 1.0, Sum: 2.9]
      [Update RS (ms): Min: 6.6, Avg: 11.4, Max: 67.4, Diff: 60.8, Sum: 204.3]
         [Processed Buffers: Min: 2, Avg: 6.7, Max: 18, Diff: 16, Sum: 121]
      [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 1.8]
      [Object Copy (ms): Min: 182.8, Avg: 238.8, Max: 242.7, Diff: 59.9, Sum: 4298.7]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.6]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.7]
      [GC Worker Total (ms): Min: 250.3, Avg: 250.5, Max: 250.7, Diff: 0.5, Sum: 4509.0]
      [GC Worker End (ms): Min: 433891.4, Avg: 433891.4, Max: 433891.5, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.6 ms]
   [Other: 3.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.6 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 0.3 ms]
   [Eden: 2368.0M(1840.0M)->0.0B(1632.0M) Survivors: 0.0B->304.0M Heap: 20.7G(36.0G)->20.2G(36.0G)]

The line that is misleading here is:

   [Eden: 2368.0M(1840.0M)->0.0B(1632.0M) Survivors: 0.0B->304.0M Heap:

It looks like the occupancy of eden is much, much more than it's capacity.