RFR: 8357818: Shenandoah doesn't use shared API for printing heap before/after GC

[William Kemper]

On Fri, 11 Jul 2025 22:03:00 GMT, Y. Srinivas Ramakrishna <ysr at openjdk.org> wrote:

>> Add logging for Shenandoah as well as Generational Shenandoah. 
>> 
>> Log samples:
>> 
>> 
>> ######################################
>> Before gc
>> ######################################
>> [0.231s][debug][gc,heap      ] GC(0) Heap Before GC invocations=0 (full 0):
>> [0.231s][debug][gc,heap      ] GC(0)  Shenandoah Heap
>> [0.231s][debug][gc,heap      ] GC(0)   100M max, 100M soft max, 100M committed, 39686K used
>> [0.231s][debug][gc,heap      ] GC(0)   400 x 256 K regions
>> [0.231s][debug][gc,heap      ] GC(0)  Status: not cancelled
>> [0.231s][debug][gc,heap      ] GC(0)  Reserved region:
>> [0.231s][debug][gc,heap      ] GC(0)   - [0x00000000f9c00000, 0x0000000100000000) 
>> [0.231s][debug][gc,heap      ] GC(0)  Collection set:
>> [0.231s][debug][gc,heap      ] GC(0)   - map (vanilla): 0x0000000000004e70
>> [0.231s][debug][gc,heap      ] GC(0)   - map (biased):  0x0000000000001000
>> [0.231s][debug][gc,heap      ] GC(0) 
>> [0.231s][debug][gc,metaspace ] GC(0) Metaspace Before GC invocations=0 (full 0):
>> [0.231s][debug][gc,metaspace ] GC(0)  Metaspace       used 153K, committed 384K, reserved 1114112K
>> [0.231s][debug][gc,metaspace ] GC(0)   class space    used 3K, committed 128K, reserved 1048576K
>> 
>> 
>> 
>> 
>> ######################################
>> After gc
>> ######################################
>> [2.067s][debug][gc,heap        ] GC(11) Heap After GC invocations=0 (full 0):
>> [2.067s][debug][gc,heap        ] GC(11)  Shenandoah Heap
>> [2.067s][debug][gc,heap        ] GC(11)   100M max, 100M soft max, 100M committed, 101356K used
>> [2.067s][debug][gc,heap        ] GC(11)   400 x 256 K regions
>> [2.067s][debug][gc,heap        ] GC(11)  Status: not cancelled
>> [2.067s][debug][gc,heap        ] GC(11)  Reserved region:
>> [2.067s][debug][gc,heap        ] GC(11)   - [0x00000000f9c00000, 0x0000000100000000) 
>> [2.067s][debug][gc,heap        ] GC(11)  Collection set:
>> [2.067s][debug][gc,heap        ] GC(11)   - map (vanilla): 0x0000000000004e70
>> [2.067s][debug][gc,heap        ] GC(11)   - map (biased):  0x0000000000001000
>> [2.067s][debug][gc,heap        ] GC(11) 
>> [2.067s][debug][gc,metaspace   ] GC(11) Metaspace After GC invocations=0 (full 0):
>> [2.067s][debug][gc,metaspace   ] GC(11)  Metaspace       used 190K, committed 384K, reserved 1114112K
>> [2.067s][debug][gc,metaspace   ] GC(11)   class space    used 4K, committed 128K, reserved 1048576K
>
>> [2.067s][debug][gc,heap        ] GC(11) Heap After GC invocations=0 (full 0):
> 
> Looks like Shenandoah/GenShen are missing `increment_total_collections(...)`, which updates the `invocations=...` part. I'd roughly expect it to equal the GC id (or be a tad smaller) `GC(11)`.
> 
>> [2.067s][debug][gc,heap        ] GC(11)  Shenandoah Heap
>> [2.067s][debug][gc,heap        ] GC(11)   100M max, 100M soft max, 100M committed, 101356K used
>> [2.067s][debug][gc,heap        ] GC(11)   400 x 256 K regions
> 
> A potential enhancement for GenShen would be to provide used region counts for old and young separately, and to add the "Generational" prefix in:
> 
>> [2.067s][debug][gc,heap        ] GC(11)  Shenandoah Heap
> 
> Rest looks good, although I want to verify that we print along all gc cycles, not just concurrent ones, as seems to be the case here.

@ysramakrishna , good catch with `increment_total_collections`. The `print_before` and `print_after` calls surround the switch case that handles all GCs (conc, degen, full).

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

PR Comment: https://git.openjdk.org/jdk/pull/26272#issuecomment-3064067648