gctoolkit

gctoolkit copied to clipboard

I find gctoolkit get the raw memory size in ZGCParser.java without the unit check. I think the line liked markStart[index] = trace.getLongGroup(2); should change to markStart[index] = trace.getMemoryInKBytes(2); . However, the lowest heap size of ZGC is 2MB，is the Mb will more suitable than the Kb？

Hmm, you might be right there, but I can't quite tell the intent of the arrays:

    private long[] markStart = new long[3];
    private long[] markEnd = new long[3];
    private long[] relocateStart = new long[3];
    private long[] relocateEnd = new long[3];

@kirk-microsoft - Are those meant to be holders for actual KByte memory numbers?

Early on I standardized on using KB when reporting memory. Some of the downstream code will have this assumption baked in.

So, should ZGC have this (KB)assumption?

Good question. I'm not stuck on having a KB resolution in the data through I'm not so happy with a MB resolution either. IMO, it's far too granular. Given that it's no loss to use KB and it's going to take a significant effort to move away from a KB resolution, this isn't really something I would prioritize ahead of other more pressing issues. So my inclination is to stick to KB unless there is a serious reason why we shouldn't.

@kirk-microsoft So it sounds like if KBytes are assumed everywhere that the code doesn't need to change?

In my zgc log, it shows like 20M(100%).

@ZhangShushu123 are you able to share that log? I'd be interested in looking at it.

Sure. The log fragment is shown as below @kirk-microsoft .

[2021-12-28T11:32:31.233+0800][7.846s][info][gc,start    ] GC(5) Garbage Collection (Proactive)
[2021-12-28T11:32:31.234+0800][7.846s][info][gc,phases   ] GC(5) Pause Mark Start 0.082ms
[2021-12-28T11:32:31.239+0800][7.852s][info][gc,phases   ] GC(5) Concurrent Mark 5.045ms
[2021-12-28T11:32:31.239+0800][7.852s][info][gc,phases   ] GC(5) Pause Mark End 0.456ms
[2021-12-28T11:32:31.240+0800][7.852s][info][gc,phases   ] GC(5) Concurrent Process Non-Strong References 0.234ms
[2021-12-28T11:32:31.240+0800][7.852s][info][gc,phases   ] GC(5) Concurrent Reset Relocation Set 0.006ms
[2021-12-28T11:32:31.243+0800][7.856s][info][gc,phases   ] GC(5) Concurrent Select Relocation Set 3.428ms
[2021-12-28T11:32:31.243+0800][7.856s][info][gc,phases   ] GC(5) Pause Relocate Start 0.087ms
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,phases   ] GC(5) Concurrent Relocate 1.660ms
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,load     ] GC(5) Load: 0.46/0.96/1.09
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,mmu      ] GC(5) MMU: 2ms/65.3%, 5ms/86.1%, 10ms/91.9%, 20ms/94.3%, 50ms/97.7%, 100ms/98.9%
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,marking  ] GC(5) Mark: 4 stripe(s), 3 proactive flush(es), 1 terminate flush(es), 1 completion(s), 0 continuation(s) 
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,reloc    ] GC(5) Relocation: Successful, 0M relocated
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,nmethod  ] GC(5) NMethods: 10 registered, 0 unregistered
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,metaspace] GC(5) Metaspace: 4M used, 4M capacity, 4M committed, 8M reserved
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,ref      ] GC(5) Soft: 3 encountered, 0 discovered, 0 enqueued
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,ref      ] GC(5) Weak: 10 encountered, 5 discovered, 0 enqueued
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,ref      ] GC(5) Final: 2780 encountered, 1780 discovered, 1780 enqueued
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,ref      ] GC(5) Phantom: 6 encountered, 4 discovered, 0 enqueued
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5) Min Capacity: 8M(0%)
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5) Max Capacity: 2048M(100%)
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5) Soft Max Capacity: 2048M(100%)
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)                Mark Start          Mark End        Relocate Start      Relocate End           High               Low         
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)  Capacity:      772M (38%)         772M (38%)         772M (38%)         772M (38%)         772M (38%)         772M (38%)    
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)   Reserve:       62M (3%)           62M (3%)           62M (3%)           62M (3%)           62M (3%)           62M (3%)     
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)      Free:     1334M (65%)        1332M (65%)        1586M (77%)        1592M (78%)        1592M (78%)        1332M (65%)    
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)      Used:      652M (32%)         654M (32%)         400M (20%)         394M (19%)         654M (32%)         394M (19%)    
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)      Live:         -               348M (17%)         348M (17%)         348M (17%)            -                  -          
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5) Allocated:         -                 2M (0%)            4M (0%)           22M (1%)             -                  -          
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5)   Garbage:         -               303M (15%)          47M (2%)           41M (2%)             -                  -          
[2021-12-28T11:32:31.245+0800][7.858s][info][gc,heap     ] GC(5) Reclaimed:         -                  -               256M (12%)         262M (13%)            -                  -          
[2021-12-28T11:32:31.245+0800][7.858s][info][gc          ] GC(5) Garbage Collection (Proactive) 652M(32%)->394M(19%)

Fragment 772M (38%) is the reason that I suggest the line liked markStart[index] = trace.getLongGroup(2); should change to markStart[index] = trace.getMemoryInKBytes(2); .

Issue has been resolved with recent changes to ZGCParser