Tenured Generation not calculated correctly

[huiwang]

As you can see in the following screenshot, the used tenured heap is greater than the tenured generation.

The log details are as follows 👍

2014-08-19T18:31:44.276+0200: 0.879: [GC [PSYoungGen: 9183K->1534K(10752K)] 9183K->3853K(33280K), 0.0103611 secs] [Times: user=0.05 sys=0.01, real=0.01 secs] 
2014-08-19T18:31:44.370+0200: 0.972: [GC [PSYoungGen: 10750K->1518K(19968K)] 13069K->9416K(42496K), 0.0136891 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 
2014-08-19T18:31:44.500+0200: 1.102: [GC [PSYoungGen: 19922K->1535K(20992K)] 27821K->16639K(43520K), 0.0185645 secs] [Times: user=0.02 sys=0.01, real=0.02 secs] 
2014-08-19T18:31:44.518+0200: 1.121: [Full GC [PSYoungGen: 1535K->0K(20992K)] [ParOldGen: 15104K->9824K(30720K)] 16639K->9824K(51712K) [PSPermGen: 8871K->8867K(22528K)], 0.0409187 secs] [Times: user=0.10 sys=0.01, real=0.04 secs] 
2014-08-19T18:31:44.569+0200: 1.171: [GC [PSYoungGen: 19394K->1532K(37888K)] 29219K->11823K(68608K), 0.0515485 secs] [Times: user=0.25 sys=0.00, real=0.05 secs] 
2014-08-19T18:31:44.964+0200: 1.567: [GC [PSYoungGen: 37821K->1522K(39424K)] 48112K->32469K(72192K), 0.0441356 secs] [Times: user=0.03 sys=0.01, real=0.04 secs] 
2014-08-19T18:31:45.009+0200: 1.611: [Full GC [PSYoungGen: 1522K->0K(39424K)] [ParOldGen: 30946K->23889K(61440K)] 32469K->23889K(100864K) [PSPermGen: 8872K->8872K(22528K)], 0.0897408 secs] [Times: user=0.16 sys=0.01, real=0.09 secs] 
2014-08-19T18:31:45.327+0200: 1.929: [GC [PSYoungGen: 37888K->21493K(82944K)] 61777K->46224K(144384K), 0.0406184 secs] [Times: user=0.03 sys=0.02, real=0.04 secs] 
2014-08-19T18:31:47.256+0200: 3.858: [GC [PSYoungGen: 82933K->13471K(89088K)] 107664K->38210K(150528K), 0.1917571 secs] [Times: user=0.25 sys=0.02, real=0.19 secs] 
2014-08-19T18:32:04.638+0200: 21.241: [GC [PSYoungGen: 75423K->9898K(112128K)] 100162K->34645K(173568K), 0.0172989 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2014-08-19T18:32:09.887+0200: 26.490: [GC [PSYoungGen: 104106K->17280K(118784K)] 779660K->692906K(835584K), 0.0109312 secs] [Times: user=0.08 sys=0.00, real=0.01 secs] 
2014-08-19T18:32:10.321+0200: 26.923: [GC [PSYoungGen: 111488K->21811K(143872K)] 787114K->697445K(860672K), 0.0323076 secs] [Times: user=0.05 sys=0.03, real=0.03 secs] 
2014-08-19T18:32:10.701+0200: 27.304: [GC [PSYoungGen: 140083K->28152K(146432K)] 815717K->708257K(863232K), 0.0649587 secs] [Times: user=0.06 sys=0.36, real=0.07 secs] 
2014-08-19T18:32:11.144+0200: 27.747: [GC [PSYoungGen: 146424K->33777K(180224K)] 826529K->718860K(897024K), 0.3053190 secs] [Times: user=0.32 sys=0.46, real=0.31 secs] 
2014-08-19T18:32:11.449+0200: 28.052: [Full GC [PSYoungGen: 33777K->0K(180224K)] [ParOldGen: 685082K->261069K(319488K)] 718860K->261069K(499712K) [PSPermGen: 25193K->25185K(47104K)], 0.1691490 secs] [Times: user=0.76 sys=0.03, real=0.17 secs] 
2014-08-19T18:32:12.032+0200: 28.634: [GC [PSYoungGen: 146432K->14632K(187392K)] 407501K->275702K(506880K), 0.0204861 secs] [Times: user=0.17 sys=0.01, real=0.02 secs] 
2014-08-19T18:32:12.475+0200: 29.078: [GC [PSYoungGen: 161064K->28297K(243712K)] 422134K->289367K(563200K), 0.0465987 secs] [Times: user=0.20 sys=0.04, real=0.05 secs] 
2014-08-19T18:32:13.115+0200: 29.718: [GC [PSYoungGen: 233097K->32450K(245760K)] 494167K->307148K(565248K), 0.0533862 secs] [Times: user=0.25 sys=0.03, real=0.05 secs] 
2014-08-19T18:32:13.168+0200: 29.771: [Full GC [PSYoungGen: 32450K->0K(245760K)] [ParOldGen: 274697K->304610K(376832K)] 307148K->304610K(622592K) [PSPermGen: 25187K->25187K(47104K)], 0.2242679 secs] [Times: user=0.64 sys=0.01, real=0.22 secs] 
2014-08-19T18:32:14.104+0200: 30.707: [GC [PSYoungGen: 204800K->19345K(311296K)] 509410K->323956K(688128K), 0.0245308 secs] [Times: user=0.04 sys=0.03, real=0.02 secs] 
2014-08-19T18:32:14.884+0200: 31.487: [GC [PSYoungGen: 290705K->25073K(312832K)] 595316K->348380K(689664K), 0.0224945 secs] [Times: user=0.03 sys=0.04, real=0.02 secs] 
2014-08-19T18:32:15.830+0200: 32.432: [GC [PSYoungGen: 296433K->24196K(316928K)] 619740K->374505K(693760K), 0.0339663 secs] [Times: user=0.03 sys=0.05, real=0.03 secs] 
2014-08-19T18:32:15.864+0200: 32.467: [Full GC [PSYoungGen: 24196K->0K(316928K)] [ParOldGen: 350308K->371086K(462848K)] 374505K->371086K(779776K) [PSPermGen: 25191K->25191K(45056K)], 0.2758607 secs] [Times: user=0.81 sys=0.03, real=0.28 secs] 
2014-08-19T18:32:16.763+0200: 33.366: [GC [PSYoungGen: 275456K->25786K(316928K)] 646542K->396873K(779776K), 0.0135895 secs] [Times: user=0.02 sys=0.01, real=0.01 secs] 
2014-08-19T18:32:17.338+0200: 33.941: [GC [PSYoungGen: 301754K->40929K(299008K)] 672841K->422420K(761856K), 0.0373049 secs] [Times: user=0.02 sys=0.04, real=0.04 secs] 
2014-08-19T18:32:17.938+0200: 34.540: [GC [PSYoungGen: 298977K->44168K(302592K)] 680468K->446130K(765440K), 0.0215347 secs] [Times: user=0.04 sys=0.03, real=0.02 secs] 
2014-08-19T18:32:17.959+0200: 34.562: [Full GC [PSYoungGen: 44168K->0K(302592K)] [ParOldGen: 401962K->443968K(544768K)] 446130K->443968K(847360K) [PSPermGen: 25191K->25191K(43008K)], 0.2072219 secs] [Times: user=1.00 sys=0.04, real=0.21 secs] 
2014-08-19T18:32:19.702+0200: 36.305: [GC [PSYoungGen: 258048K->28059K(305664K)] 702016K->472027K(850432K), 0.0492165 secs] [Times: user=0.33 sys=0.01, real=0.05 secs] 
2014-08-19T18:32:20.283+0200: 36.886: [GC [PSYoungGen: 259477K->52735K(303616K)] 703445K->536427K(848384K), 0.0342157 secs] [Times: user=0.26 sys=0.04, real=0.03 secs] 
2014-08-19T18:32:20.317+0200: 36.920: [Full GC [PSYoungGen: 52735K->0K(303616K)] [ParOldGen: 483692K->191988K(309248K)] 536427K->191988K(612864K) [PSPermGen: 25286K->25286K(43008K)], 0.2311834 secs] [Times: user=0.86 sys=0.01, real=0.23 secs] 
2014-08-19T18:32:20.886+0200: 37.489: [GC [PSYoungGen: 250880K->160K(260608K)] 442868K->265876K(569856K), 0.1618948 secs] [Times: user=0.27 sys=0.00, real=0.16 secs] 
2014-08-19T18:32:21.048+0200: 37.651: [Full GC [PSYoungGen: 160K->0K(260608K)] [ParOldGen: 265716K->228889K(374784K)] 265876K->228889K(635392K) [PSPermGen: 25286K->25286K(40960K)], 0.0719762 secs] [Times: user=0.19 sys=0.00, real=0.07 secs] 
2014-08-19T18:32:21.341+0200: 37.944: [GC [PSYoungGen: 205824K->96K(282112K)] 434713K->376441K(806400K), 0.3774080 secs] [Times: user=0.81 sys=0.06, real=0.38 secs] 
2014-08-19T18:32:22.112+0200: 38.715: [GC [PSYoungGen: 205920K->160K(282112K)] 582265K->376505K(806400K), 0.1671024 secs] [Times: user=0.32 sys=0.00, real=0.17 secs] 
2014-08-19T18:32:23.012+0200: 39.614: [GC [PSYoungGen: 169993K->192K(206336K)] 690962K->521177K(923136K), 0.0746708 secs] [Times: user=0.10 sys=0.01, real=0.07 secs] 
2014-08-19T18:32:23.086+0200: 39.689: [GC [PSYoungGen: 192K->0K(283136K)] 521177K->521001K(999936K), 0.3653322 secs] [Times: user=0.23 sys=0.00, real=0.37 secs] 
2014-08-19T18:32:23.452+0200: 40.055: [Full GC [PSYoungGen: 0K->0K(283136K)] [ParOldGen: 521001K->447205K(626688K)] 521001K->447205K(909824K) [PSPermGen: 25312K->25312K(38912K)], 0.6084720 secs] [Times: user=0.58 sys=0.01, real=0.61 secs] 
2014-08-19T18:32:24.061+0200: 40.663: [GC [PSYoungGen: 0K->0K(281600K)] 447205K->447205K(998400K), 0.1393347 secs] [Times: user=0.34 sys=0.00, real=0.14 secs] 
2014-08-19T18:32:24.200+0200: 40.803: [Full GC [PSYoungGen: 0K->0K(281600K)] [ParOldGen: 447205K->444919K(628736K)] 447205K->444919K(910336K) [PSPermGen: 25312K->25090K(36864K)], 0.8198396 secs] [Times: user=1.12 sys=0.01, real=0.82 secs] 

[chewiebug]

Hi,

Thank you for raising this issue! It looks like there is an inconsistency between calculation of tenured size and usage. I'll have to look into calculation of both of them.

Best regards,
Jörg

[chewiebug]

Hi,

I have pushed a fix to the repository. Now tenured generation is drawn as a jagged line (not rectangular any more). Like this, used tenured heap should never be bigger than total tenured heap any more.

If you should still find problems with drawing of used / total tenured heap, please reopen this issue.

Best regards,
Jörg