JDK-8141141 : Young and Old gen PLAB stats are similar in output with -XX:+PrintPLAB
  • Type: Enhancement
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 9
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2015-11-02
  • Updated: 2016-03-15
  • Resolved: 2016-03-02
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.
JDK 9
9 b110Fixed
Related Reports
Blocks :  
Relates :  
Relates :  
Description
We have -XX:+PrintPLAB flag which is allow to get plab allocation statistics. 

Output looks like (used -XX:+PrintGC -XX:+PrintPLAB options):

#2: [GC pause (G1 Evacuation Pause) (young) (allocated = 519344 wasted = 4486 unused = 0 used = 514858 undo_waste = 0 region_end_waste = 0 regions filled = 2 direct_allocated = 4944 failure_used = 0 failure_waste = 0)  (plab_sz = 102971 desired_plab_sz = 65536) 
 (allocated = 3305338 wasted = 25813 unused = 806 used = 3278719 undo_waste = 0 region_end_waste = 0 regions filled = 8 direct_allocated = 66 failure_used = 0 failure_waste = 0)  (plab_sz = 655743 desired_plab_sz = 65536) 
 53M->53M(376M), 0,1360649 secs]
#3: [GC pause (G1 Evacuation Pause) (young) (allocated = 262144 wasted = 224 unused = 0 used = 261920 undo_waste = 0 region_end_waste = 0 regions filled = 3 direct_allocated = 0 failure_used = 0 failure_waste = 0)  (plab_sz = 52384 desired_plab_sz = 60993) 
 (allocated = 939085 wasted = 446 unused = 28700 used = 909939 undo_waste = 0 region_end_waste = 0 regions filled = 16 direct_allocated = 3123 failure_used = 0 failure_waste = 0)  (plab_sz = 181987 desired_plab_sz = 65536) 
 79M->79M(599M), 0,1408361 secs]

Each GC event has young and old PLAB statistics.

In case if we use only -XX:+PrintPLAB, output looks like:

 (allocated = 258154 wasted = 2187 unused = 0 used = 255967 undo_waste = 0 region_end_waste = 0 regions filled = 7 direct_allocated = 3990 failure_used = 0 failure_waste = 0)  (plab_sz = 51193 desired_plab_sz = 38394) 
 (allocated = 1058480 wasted = 8538 unused = 905 used = 1049037 undo_waste = 0 region_end_waste = 0 regions filled = 43 direct_allocated = 9962 failure_used = 0 failure_waste = 0)  (plab_sz = 209807 desired_plab_sz = 65536) 
 (allocated = 912780 wasted = 7571 unused = 0 used = 905209 undo_waste = 0 region_end_waste = 0 regions filled = 2 direct_allocated = 4724 failure_used = 0 failure_waste = 0)  (plab_sz = 181041 desired_plab_sz = 65536) 
 (allocated = 5554141 wasted = 43337 unused = 1083 used = 5509721 undo_waste = 0 region_end_waste = 0 regions filled = 11 direct_allocated = 123 failure_used = 0 failure_waste = 0)  (plab_sz = 1101944 desired_plab_sz = 65536) 

There young and old stats are interleaved.

It would be good to point which PLAB statistics is printed - for young or for old gen.
Comments
Current implementation suggestion: * [0.330s][debug][gc,plab ] GC(0) Young PLAB allocation: allocated: 1825632B, wasted: 29424B, unused: 2320B, used: 1793888B, undo waste: 0B, * [0.330s][debug][gc,plab ] GC(0) Young other allocation: region end waste: 0B, regions filled: 2, direct allocated: 271520B, failure used: 0B, failure wasted: 0B * [0.330s][debug][gc,plab ] GC(0) Young sizing: calculated: 358776B, actual: 358776B * [0.330s][debug][gc,plab ] GC(0) Old PLAB allocation: allocated: 427248B, wasted: 592B, unused: 368584B, used: 58072B, undo waste: 0B, * [0.330s][debug][gc,plab ] GC(0) Old other allocation: region end waste: 0B, regions filled: 1, direct allocated: 41704B, failure used: 0B, failure wasted: 0B * [0.330s][debug][gc,plab ] GC(0) Old sizing: calculated: 11608B, actual: 11608B changes: - add "Young"/"Old" identifier to show "generation" - split information into multiple lines; the "other allocation" and "sizing" are optional. "other allocation" when using G1, "sizing" only when ResizePLAB is enabled - values are in bytes now (with units), not heapwords
01-03-2016

I tend to think that we will best fix this problem when going through the log messages during the unified gc logging work.
11-11-2015