chewiebug / GCViewer

Fork of tagtraum industries' GCViewer. Tagtraum stopped development in 2008, I aim to improve support for Sun's / Oracle's java 1.6+ garbage collector logs (including G1 collector)
https://github.com/chewiebug/GCViewer/wiki
Other
4.47k stars 979 forks source link

Total promotion can get negative #235

Open theobisproject opened 4 years ago

theobisproject commented 4 years ago

GCViewer reports a negative total promotion for this Java 11 G1GC log: gc.log.gz

I made a quick check and it seems that the updatePromotion in GCModel calculates for some GC Events negative promotion values and adds them to the total promotion. Maybe a simple >= 0 check will fix the problem if the calculation is correct.

cmoetzing commented 4 years ago

As far as I understand the situation the fix won't be that simple.

[18.709] GC(12) [Pause Young (Normal) (G1 Evacuation Pause) [18.709] 

[Eden      140288K -> 0K     (143360K),  0.0 secs][18.709] 140288
[Survivor  16384K  -> 13312K (20480K),   0.0 secs][18.709] 3072
[Old       8192K   -> 13312K (0K),   0.0 secs][18.709] -5230
[Humongous 18432K  -> 8192K  (0K),   0.0 secs][18.709] 10240
[Metaspace 48235K  -> 48235K (1093632K), 0.0 secs]     0

181248K->32768K(262144K), 0.009073000000000001 secs]       148480

Eden 140288 - All 148480 = -8192

This is the first GC line that would give a negative promotion of -8192. As you stated updatePromotion defines promotion as (preEden-postEden) - (preAll-postAll). I think there is a false assumption here: the overall change only comes from promotion But since there is also change in Survivor, Old and Humongous space this can not be correct, right?

~~There is one more strange thing. The pattern is described as [Old PRE -> POST (TOTAL)...] which would mean that the total amount is 0 while post used is 13312K? [Old 8192K -> 13312K (0K), 0.0 secs][18.709] -5230~~

Can someone with G1 experience enlighten me?

Edit 1: Old and Humongous display 0k total in the parsed event only, they do not have it in the original log. I scratched that part.

theobisproject commented 4 years ago

@cmoetzing Thank you for your input! I also hope someone can enlighten me how to fix this properly 😉 As far as I know the G1 Humongous spaces should not account to the promotion since they are special regions which are not moved and only are created and when no longer needed garbage collected. So I don't think they should be included in the (preAll - postAll) calculation. Also not sure if this is an G1 only problem.

I also rechecked my fix with the provided logfile against gceasy.io. The results are the following: gceasy.io grafik GCViewer grafik So the results currently are too high.

I also created this artificial log file with the GC event from your comment to check what they calculate for events I fixed with the linked PR: gc-artificial.log gceasy.io grafik GCViewer grafik

So it seems my fix works only in some cases. Otherwise the full log file would display the same promotion.

cmoetzing commented 4 years ago

I understand why the current calculations overestimate in some cases. The method GCModel#updatePromotion(GCEvent event) looks for the first YOUNG event which is [18.709s][info][gc,heap ] GC(12) Eden regions: 137->0(140). It will always ignore the other YOUNG event [18.709s][info][gc,heap ] GC(12) Survivor regions: 16->13(20) which is bad. If something is promoted to survivor it is still YOUNG and should not be counted towards promotion per definition of JavaDoc:

promotion information for all young collections (how much memory was promoted to tenured space per young collection?)

I would fix this issue by counting only [18.709s][info][gc,heap ] GC(12) Old regions: 8->13 towards promotion. Now there is one last question to answer: Is an object that is put into the humongous region to be counted as promotion? I understand that it skips YOUNG completely because it would be too big?

cmoetzing commented 4 years ago

I tried to implement a fix in #242 . At the moment I am thinking about whether updatePromotion should be moved to DataReader since the available information differs and only the reader can really decide what calculation is correct.

ecki commented 4 years ago

Now there is one last question to answer: Is an object that is put into the humongous region to be counted as promotion? I understand that it skips YOUNG completely because it would be too big?

I would say for G1 the humongous allocations are important. So if we don't count it to the promotion (which might be a good idea since it can be rather missleading) then we should offer it as a separate measurement (at least as far as possible).

theobisproject commented 4 years ago

Now there is one last question to answer: Is an object that is put into the humongous region to be counted as promotion? I understand that it skips YOUNG completely because it would be too big?

According to this Oracle article https://www.oracle.com/technical-resources/articles/java/g1gc.html the humongous allocation happens directly in the old generation.

For G1 GC, any object that is more than half a region size is considered a "Humongous object". Such an object is allocated directly in the old generation into "Humongous regions".

So this is clearly no promotion from a young generation to an old generation. As @ecki pointed the information about humongous regions is sometime really valuable.

cmoetzing commented 4 years ago

Wouldn't it be best to divide young and tenured into eden, survivor, old and humongous then? No reason to hide any info.

theobisproject commented 4 years ago

I'm generally agreeing with you but this would make sense for G1GC and not for the other supported garbage collectors. Not sure such a specialized solution for 1 garbage collector will be accepted by the maintainer.