JDK-8232100 : GC timings should use proper units for heap sizes
  • Type: Enhancement
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 8,11,13,14
  • Priority: P4
  • Status: Open
  • Resolution: Unresolved
  • Submitted: 2019-10-10
  • Updated: 2019-12-11
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
tbdUnresolved
Related Reports
Relates :  
JDK-8217315 - Proper units should print more significant digits
Relates :  
JDK-8232102 - Shenandoah: print everything in proper units
Description
Currently, GC logs unconditionally use "M" as the suffix for heap sizes, which makes GC logs too coarse on smaller heaps. See for example:

[0.539s][info][gc] GC(108) Pause Young (Normal) (G1 Evacuation Pause) 35M->35M(46M) 1.295ms
[0.541s][info][gc] GC(109) Pause Young (Normal) (G1 Evacuation Pause) 39M->39M(48M) 1.611ms
[0.545s][info][gc] GC(110) Pause Young (Normal) (G1 Evacuation Pause) 44M->44M(58M) 2.600ms
[0.549s][info][gc] GC(111) Pause Young (Normal) (G1 Evacuation Pause) 49M->49M(59M) 1.513ms
[0.552s][info][gc] GC(112) Pause Young (Normal) (G1 Evacuation Pause) 53M->53M(62M) 1.589ms

There is actually a bit of progress on every cycle here, but the "M" coarseness hides it. JDK-8217315 improved the precision of proper units facility, and we should consider using that for printing GC heap data. For example:
 https://cr.openjdk.java.net/~shade/8232100/webrev.01/

Example log after that (timings are worse, because it is fastdebug build):

[0.965s][info][gc] GC(54) Pause Young (Normal) (G1 Evacuation Pause) 39454K->39513K(56320K) 3.936ms
[0.969s][info][gc] GC(55) Pause Young (Normal) (G1 Evacuation Pause) 42582K->42561K(56320K) 3.709ms
[0.974s][info][gc] GC(56) Pause Young (Normal) (G1 Evacuation Pause) 45630K->45597K(60416K) 3.669ms
[0.981s][info][gc] GC(57) Pause Young (Normal) (G1 Evacuation Pause) 48666K->48633K(60416K) 3.930ms
[0.986s][info][gc] GC(58) Pause Young (Normal) (G1 Evacuation Pause) 51705K->51677K(60416K) 3.552ms
[0.991s][info][gc] GC(59) Pause Young (Normal) (G1 Evacuation Pause) 54749K->54717K(63488K) 4.192ms
Comments
RFR: https://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2019-October/027328.html
10-10-2019