RFR: 8267924: Misleading G1 eager reclaim detail logging

[Thomas Schatzl]

On Wed, 2 Jun 2021 13:23:25 GMT, Thomas Schatzl <tschatzl at openjdk.org> wrote:

> Hi,
> 
>   can I have reviews for this change that brushes up `gc+humongous` logging?
> 
> In particular, during review of some logs several issues were found with the logging.
> Both the "Live humongous region" and "Dead humongous region" logs
>   * the remset count is always zero at the point of printing (end of gc) because G1 never pushes new cross-region references into remembered set entries during gc, and for candidates we actually just flushed them
>   * the reclaim candidate flag is always zero at that point: if it got a "Live humongous" message, the source of that information must be false at that point. If "Dead humongous", it must have been true (one). 
> 
> This change modifies the log output to try to give useful information: first, g1 prints information for all humongous regions when deciding whether something is a candidate. This means that the printed information is current. At the end of gc only reclaimed regions are printed, repeating the information from the printout at the beginning does not give more information.
> 
> E.g. a sample output from the test case
> 
> First, all humongous regions
> 
> Humongous region 0 (object size 41943056 @ 0x00000000f8000000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
> Humongous region 71 (object size 25165840 @ 0x00000000fc700000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
> Humongous region 41 (object size 4194320 @ 0x00000000fa900000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
> Humongous region 46 (object size 25165840 @ 0x00000000fae00000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
> 
> Later only reclaimed ones:
> 
> Reclaimed humongous region 46 (object size 25165840 @ 0x00000000fae00000)
> 
> 
> Instead of currently:
> 
> 
> Live humongous region 789 object size 2160888 start 0x00000006e2a00000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
> 
> or 
> 
> Dead humongous region 182 object size 16777232 start 0x000000074b600000 with remset 0 code roots 0 is marked 0 reclaim candidate 1 type array 1
> 
> 
> This unfortunately kind of invalidates some websites trying to explain these log messages, but I still prefer to have useful output.
> 
> Thanks,
>   Thomas

src/hotspot/share/gc/g1/g1YoungGCPostEvacuateTasks.cpp line 141:

> 139:     // are currently allocated into.
> 140:     uint region_idx = r->hrm_index();
> 141:     if (!g1h->is_humongous_reclaim_candidate(region_idx)) {

Fwiw, the reason why the second clause has been removed is because it is useless: G1 does not add remembered set entries during gc, so if the remembered set has been empty before, it will be empty again.
Humongous regions with a large enough remembered set at the start are never candidates, and ones that are candidates have all of their outstanding references checked and if that is the case, their candidate state revoked, which is reflected in the `is_humongous_reclaim_candidate` check.

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

PR: https://git.openjdk.java.net/jdk/pull/4305