While running some G1 performance tests, Charlie Hunt discovered some unusual young GC pauses where the eden size would suddenly drop from 5G in one pause to 8M in the next.

The following log snippet illustrates the issue:

---------------------
Here's the GC before, "the GC", and the GC after that drop in Eden.

I'm trying to understand why we dropped the size of Eden. The only thing that stands out to me is in "the GC" where the eden size is dropped, the "Update RS" times are about 10x larger than the before or after GCs. Does G1 happen to know, or predict, how much time it's going to spend in an "Update RS" on the next GC?

Here's the GCs:

136.678: [GC pause (young), 0.13907365 secs]
   [Parallel Time: 129.2 ms]
      [GC Worker Start (ms): 136677.9 136678.0 136678.0 136678.0 136678.0 136678.0 136678.0 136678.0 136678.0 136678.0
       Avg: 136678.0, Min: 136677.9, Max: 136678.0, Diff: 0.1]
      [Ext Root Scanning (ms): 1.0 8.3 1.0 1.0 1.0 1.0 1.3 1.0 0.9 0.9
       Avg: 1.7, Min: 0.9, Max: 8.3, Diff: 7.5]
      [Update RS (ms): 1.1 0.0 1.0 1.0 1.5 1.3 0.9 1.5 1.0 1.0
       Avg: 1.0, Min: 0.0, Max: 1.5, Diff: 1.5]
         [Processed Buffers : 2 0 8 21 3 2 1 1 5 1
          Sum: 44, Avg: 4, Min: 0, Max: 21, Diff: 21]
      [Scan RS (ms): 6.2 0.0 6.3 6.3 5.7 5.9 6.1 5.7 6.3 6.3
       Avg: 5.5, Min: 0.0, Max: 6.3, Diff: 6.3]
      [Object Copy (ms): 119.3 119.2 119.3 119.3 119.4 119.3 119.3 119.3 119.3 119.4
       Avg: 119.3, Min: 119.2, Max: 119.4, Diff: 0.2]
      [Termination (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
       Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0]
         [Termination Attempts : 1 1 1 1 1 1 1 1 1 1
          Sum: 10, Avg: 1, Min: 1, Max: 1, Diff: 0]
      [GC Worker End (ms): 136805.5 136805.6 136805.6 136805.6 136805.6 136805.6 136805.5 136805.5 136805.6 136805.5
       Avg: 136805.6, Min: 136805.5, Max: 136805.6, Diff: 0.1]
      [GC Worker (ms): 127.6 127.6 127.6 127.6 127.6 127.6 127.5 127.5 127.6 127.5
       Avg: 127.6, Min: 127.5, Max: 127.6, Diff: 0.1]
      [GC Worker Other (ms): 1.6 1.6 1.6 1.6 1.7 1.7 1.7 1.7 1.7 1.7
       Avg: 1.7, Min: 1.6, Max: 1.7, Diff: 0.1]
   [Clear CT: 0.9 ms]
   [Other: 9.0 ms]
      [Choose CSet: 0.1 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 8.3 ms]
   [Eden: 5040M(5040M)->0B(5040M) Survivors: 280M->280M Heap: 5722M(26624M)->685M(26624M)]
 [Times: user=1.29 sys=0.00, real=0.14 secs]
136.818: [GC pause (young), 0.16131867 secs]
   [Parallel Time: 159.6 ms]
      [GC Worker Start (ms): 136817.6 136817.6 136817.6 136817.6 136817.6 136817.6 136817.6 136817.6 136817.6 136817.6
       Avg: 136817.6, Min: 136817.6, Max: 136817.6, Diff: 0.1]
      [Ext Root Scanning (ms): 1.0 1.0 1.0 1.0 1.0 1.3 0.9 1.0 3.9 0.9
       Avg: 1.3, Min: 0.9, Max: 3.9, Diff: 3.0]
      [Update RS (ms): 13.2 13.3 13.1 16.3 13.9 13.7 13.5 13.1 11.2 13.8
       Avg: 13.5, Min: 11.2, Max: 16.3, Diff: 5.1]
         [Processed Buffers : 16 14 9 10 10 7 12 20 5 11
          Sum: 114, Avg: 11, Min: 5, Max: 20, Diff: 15]
      [Scan RS (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.1 0.0 0.0
       Avg: 0.0, Min: 0.0, Max: 0.1, Diff: 0.1]
      [Object Copy (ms): 143.7 142.8 142.8 139.8 142.1 142.2 142.4 142.9 141.7 142.3
       Avg: 142.3, Min: 139.8, Max: 143.7, Diff: 3.9]
      [Termination (ms): 0.0 0.9 1.0 0.8 1.0 0.7 1.1 0.9 1.2 1.0
       Avg: 0.9, Min: 0.0, Max: 1.2, Diff: 1.2]
         [Termination Attempts : 1 3578 3521 3176 3473 2622 3593 3096 4064 3232
          Sum: 30356, Avg: 3035, Min: 1, Max: 4064, Diff: 4063]
      [GC Worker End (ms): 136975.6 136975.6 136975.6 136975.6 136975.6 136975.6 136975.6 136975.6 136975.6 136975.6
       Avg: 136975.6, Min: 136975.6, Max: 136975.6, Diff: 0.0]
      [GC Worker (ms): 158.0 158.0 158.0 158.0 158.0 158.0 158.0 158.0 157.9 158.0
       Avg: 158.0, Min: 157.9, Max: 158.0, Diff: 0.1]
      [GC Worker Other (ms): 1.6 1.6 1.6 1.6 1.7 1.7 1.7 1.7 1.7 1.7
       Avg: 1.7, Min: 1.6, Max: 1.7, Diff: 0.1]
   [Clear CT: 0.1 ms]
   [Other: 1.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 0.7 ms]
   [Eden: 8192K(5040M)->0B(5032M) Survivors: 280M->288M Heap: 686M(26624M)->687M(26624M)]
 [Times: user=1.57 sys=0.01, real=0.16 secs]
141.846: [GC pause (young), 0.15612571 secs]
   [Parallel Time: 151.1 ms]
      [GC Worker Start (ms): 141845.9 141845.9 141845.9 141845.9 141845.9 141845.9 141845.9 141847.8 141847.8 141847.9
       Avg: 141846.5, Min: 141845.9, Max: 141847.9, Diff: 2.1]
      [Ext Root Scanning (ms): 1.6 1.5 3.0 1.3 1.6 2.6 1.3 0.0 0.0 0.0
       Avg: 1.3, Min: 0.0, Max: 3.0, Diff: 3.0]
      [Update RS (ms): 1.1 2.3 0.0 1.7 1.2 0.1 1.4 0.9 0.9 1.0
       Avg: 1.1, Min: 0.0, Max: 2.3, Diff: 2.3]
         [Processed Buffers : 20 1 0 1 33 19 9 8 1 2
          Sum: 94, Avg: 9, Min: 0, Max: 33, Diff: 33]
      [Scan RS (ms): 6.1 4.8 5.6 6.3 6.5 5.8 5.8 5.8 6.5 5.6
       Avg: 5.9, Min: 4.8, Max: 6.5, Diff: 1.7]
      [Object Copy (ms): 138.4 138.1 138.1 137.4 137.5 138.2 138.1 138.0 139.2 140.1
       Avg: 138.3, Min: 137.4, Max: 140.1, Diff: 2.7]
      [Termination (ms): 2.0 2.5 2.4 2.4 2.4 2.4 2.4 2.5 0.5 0.3
       Avg: 2.0, Min: 0.3, Max: 2.5, Diff: 2.2]
         [Termination Attempts : 1 1982 1849 1803 1583 1467 1810 1922 1628 1059
          Sum: 15104, Avg: 1510, Min: 1, Max: 1982, Diff: 1981]
      [GC Worker End (ms): 141995.0 141995.0 141995.0 141995.0 141995.0 141995.0 141995.0 141995.0 141995.0 141995.0
       Avg: 141995.0, Min: 141995.0, Max: 141995.0, Diff: 0.0]
      [GC Worker (ms): 149.2 149.2 149.1 149.1 149.1 149.1 149.1 147.2 147.2 147.1
       Avg: 148.6, Min: 147.1, Max: 149.2, Diff: 2.1]
      [GC Worker Other (ms): 2.0 2.0 2.0 2.0 2.0 2.0 2.0 3.9 3.9 4.0
       Avg: 2.6, Min: 2.0, Max: 4.0, Diff: 2.1]
   [Clear CT: 0.7 ms]
   [Other: 4.3 ms]
      [Choose CSet: 0.1 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Free CSet: 3.7 ms]
   [Eden: 5032M(5032M)->0B(5032M) Survivors: 288M->288M Heap: 5719M(26624M)->692M(26624M)]
 [Times: user=1.49 sys=0.00, real=0.16 secs]

---------------------------

In the above snippet:
* the Eden in the first pause is sized at 5040M.
* The first pause has an elapsed duration of 139.1 ms.
* The time stamp on the first pause is 136.678 - which means it ended at 136.8171.

* The Eden in the second pause is only 8M (which is one region given the heap sizing parameters).
* The timestamp of the second pause is 136.818

This indicates that the application did not run between these two GCs.