RFR: 8270100: Fix some inaccurate GC logging

[Thomas Schatzl]

On Thu, 8 Jul 2021 15:19:01 GMT, Volker Simonis <simonis at openjdk.org> wrote:

> If running with `-Xlog:gc+heap*=trace` the JVM will print the extra per thread amount which is added to the new generation on resize:
> 
> [0,105s][debug][gc,ergo,heap ] GC(0) New generation size 34112K->34176K [eden=27392K,survivor=3392K]
> [0,105s][trace][gc,ergo,heap ] GC(0) [allowed 0K extra for 0 threads]
> 
> Currently this will always print "0K extra for 0 threads" no matter how much extra space was added.
> 
> Also, the shrink factor will always be printed to be 0%, even if we run with `-XX:-ShrinkHeapInSteps` which pins the shrink factor at 100%:
> 
> [13,213s][trace][gc,heap ] GC(34) shrink_bytes: 463564,0K current_shrink_factor: 0 new shrink factor: 0 _min_heap_delta_bytes: 192,0K
> [13,239s][trace][gc,heap ] GC(34) Shrinking tenured generation from 531852K to 68288K
> 
> 
> The fix is trivial.

I would prefer to not change semantics for heap sizing without lots of testing, and discussing the results. People have come to expect particular behavior, and actually "decaying" the shrink factor on every `CardGeneration::compute_new_size()` call makes sense. This makes shrinking the heap more slowly and less surprising. Consider the situation when you have the following sequence of shrink (s), no change (n) heap changes:

s - s - s - n - n - ... lots of n ... - n - s

On the last s, the GC would shrink 100% of the suggested value, which is kind of surprising given that the many "no-changes" gcs that would have indicated the application is kind of stable now (or you started another round in your benchmark). Generally it is also a good idea to be very reluctant with heap decreases as it typically has a significant performance impact during further operation. Too much heap shrinking tends to also just cause the next gc(s) to increase the heap again, i.e. ending up in wasted cpu time :)

Fwiw, for this issue, I would split `adjust_for_thread_increase` into two methods: one calculating the `thread_increase_size`, and the original `adjust_for_thread_increase` take that value as a parameter. 

Repeating the calculation at the logging as suggested by @albertnetymk gives different results on boundary conditions (i.e. the overflow checks are missing. Strangely on any overflow condition, `thread_increase_size` does not factor in at all into the `desired_new_size`. I think this is a bug; my preferred alternative would be to maximize the `thread_increase_size` to just not overflow instead - but that is another issue(!)). Another reason why I would prefer to separate the calculation of that value from the calculation of the desired_new_size is that these seem to logically be two separate steps, so that makes sense anyway imho.

I agree with @albertnetymk that it is preferable to not have the conditions in the log message to make them as simple as possible - so I would probably just set `current_shrink_factor` and `_shrink_factor` to 100 at the top of `CardGeneration::compute_new_size` if `ShrinkHeapInSteps` is false. In addition to that probably put these variable declarations at the start of the shrinking calculations block, somewhere close to

size_t shrink_bytes = 0;

Calling `Threads::number_of_non_daemon_threads` another time for the log message does not seem to be a problem, but if you wanted, that `calculate_thread_increase_size()` could also return the thread count used for the calculation.

Of course, I did not run and test my suggestions.

Three people, three opinions, but maybe there's a middle ground to be found somewhere :p

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

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