Minor question about logging

[Thomas Schatzl]

Hi,

On 08.03.20 06:01, Eugeniu Rabii wrote:
> Hello,
> 
> I have a very simple program that constantly allocates some byte arrays 
> (of 2 MB) each (running with the latest jdk-13). I run it with :
> 
> -Xms20M
> -Xmx20M
> -Xmn10M
> "-Xlog:heap*=debug" "-Xlog:gc*=debug" "-Xlog:ergo*=debug"
> 
> 
> For example:
> 
>      public static void main(String[] args) {
[...]
>      }
> 
> In logs, I see something that is puzzling me:
> 
> 
> [0.066s][debug][gc,ergo       ] Request concurrent cycle initiation 
> (requested by GC cause). GC cause: G1 Humongous Allocation
> [0.066s][debug][gc,heap       ] GC(0) Heap before GC invocations=0 (full 
> 0): garbage-first heap   total 20480K, used 6908K [0x00000007fec00000, 
> 0x0000000800000000)
> [0.066s][debug][gc,heap       ] GC(0)   region size 1024K, 1 young 
> (1024K), 0 survivors (0K)
> 
> OK, so Heap Before: 1 young, 0 survivors.
> 
> Then:
> 
> [0.071s][info ][gc,heap        ] GC(0) Eden regions: 1->0(9)
> [0.071s][info ][gc,heap        ] GC(0) Survivor regions: 0->1(2)
> [0.071s][info ][gc,heap        ] GC(0) Old regions: 0->0
> 
> So the next cycle will have 9 Eden Regions and 2 Survivor ones (at least 
> this is how I read the source code of where this is logged)

The nine eden regions are estimates based on pause time and some factors 
like estimated allocation rate. The two survivor ones are actually 
survivor regions allowed in the current GC (allowed survivor region 
length is always determined at the start of GC). It should probably read

Survivor regions: 0(2)->1

In this case the limit for entire young gen is G1MaxNewSizePercent, 
which by default is 60%; 60% of 20M is 12M, which is distributed across 
Survivor and Eden according to SurvivorRatio (=8).

> 
> Then a GC(1) concurrent cycle happens:
> 
> [0.071s][info ][gc             ] GC(1) Concurrent Cycle
> 
> And the next cycle is where I fail to understand the logging:
> 
> [0.076s][debug][gc,heap           ] GC(2) Heap before GC invocations=2 
> (full 0): garbage-first heap   total 20480K, used 7148K 
> [0x00000007fec00000, 0x0000000800000000)
> [0.076s][debug][gc,heap           ] GC(2)   region size 1024K, 2 young 
> (2048K), 1 survivors (1024K)
> 
> How come 2 young, 1 survivors? When the previous cycle said 9 Eden, 2 
> Survivor.

Humongous allocations can make initial estimations about young gen size 
obsolete.

I.e. the humongous allocations (directly into old gen) made old gen 
occupancy cross the current threshold to start old gen reclamation. 
Otherwise the humongous objects would have filled up the entire heap, 
causing full gc.

Thanks,
   Thomas