JBoss 4.05 memory issue

[bakry]

hi,

I have a problem with jboss memory utilization, I am running one application with minimal hits (memory needs) on a 4.0.5 jboss server... here is the config of jboss >>

-Xms128m -Xmx1500m -XX:MaxPermSize=512m -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000

the server start with 128 and keeps eating memory very fast till it reach 1 to 1.3 GB (which is not normal for my application needs).... anyway my issue is that total memory is very high while the server has high free memory... what I understand is that on garbage collector the server should shrink the heap and thus the total memory...

here is the web-console display:


Free Memory: 771 MB

Max Memory: 1365 MB

Total Memory: 1344 MB


here is my memory pool view of the ServerInfo jmx bean:


Total Memory Pools: 5

Pool: Code Cache (Non-heap memory)

Peak Usage : init:1572864, used:31555520, committed:31621120, max:33554432
Current Usage : init:1572864, used:31503104, committed:31621120, max:33554432


|----------------------------------------------------------------| committed:30.16Mb
+---------------------------------------------------------------------+
|////////////////////////////////////////////////////////////////| | max:32Mb
+---------------------------------------------------------------------+
|----------------------------------------------------------------| used:30.04Mb


Pool: PS Eden Space (Heap memory)

Peak Usage : init:34603008, used:411435008, committed:411435008, max:535560192
Current Usage : init:34603008, used:20664872, committed:179044352, max:179044352


|---------------------------------------------------------------------| committed:170.75Mb
+---------------------------------------------------------------------+
|//////// | max:170.75Mb
+---------------------------------------------------------------------+
|-------| used:19.71Mb


Pool: PS Survivor Space (Heap memory)

Peak Usage : init:5767168, used:178913200, committed:178913280, max:178913280
Current Usage : init:5767168, used:33169288, committed:178913280, max:178913280


|---------------------------------------------------------------------| committed:170.62Mb
+---------------------------------------------------------------------+
|//////////// | max:170.62Mb
+---------------------------------------------------------------------+
|-----------| used:31.63Mb


Pool: PS Old Gen (Heap memory)

Peak Usage : init:92274688, used:1073741664, committed:1073741824, max:1073741824
Current Usage : init:92274688, used:674116608, committed:1073741824, max:1073741824


|---------------------------------------------------------------------| committed:1Gb
+---------------------------------------------------------------------+
|/////////////////////////////////////////// | max:1Gb
+---------------------------------------------------------------------+
|------------------------------------------| used:642.89Mb


Pool: PS Perm Gen (Non-heap memory)

Peak Usage : init:16777216, used:141709616, committed:192937984, max:268435456
Current Usage : init:16777216, used:81833240, committed:104857600, max:268435456


|--------------------------| committed:100Mb
+---------------------------------------------------------------------+
|///////////////////// | | max:256Mb
+---------------------------------------------------------------------+
|--------------------| used:78.04Mb










is there any tuning parameters I could use to change this behavior, I get out of memory error every week....


Regards

[peterj]

Please look at my presentation on Java heap tuning:

http://www.cecmg.de/doc/tagung_2007/agenda07/24-mai/2b3-peter-johnson/index.html

You need to use the command line options to gather garbage collection statistics and go from there. If it is true that your heap is filling up and major collection are not freeing it, then you have a leak in your application. You can use VisualVM to help you analyze that objects your app is not freeing up.

[bakry]

hi peter

thanks for the reply, I have looked at your presentation before (it was very helpfull)... here is what I got in the GC details during a load test on my server


23.382: [GC [PSYoungGen: 55462K->4583K(78848K)] 55462K->4583K(254976K), 0.0817857 secs]
23.464: [Full GC [PSYoungGen: 4583K->0K(78848K)] [PSOldGen: 0K->3770K(176128K)] 4583K->3770K(254976K) [PSPermGen: 9172K->9172K(20480K)], 0.2574611 secs]
36.571: [GC [PSYoungGen: 67584K->5088K(78848K)] 71354K->8858K(254976K), 0.0819799 secs]
49.827: [GC [PSYoungGen: 72672K->5776K(78848K)] 76442K->9546K(254976K), 0.0263934 secs]
59.113: [GC [PSYoungGen: 73360K->11253K(78848K)] 77130K->15313K(254976K), 0.0908562 secs]
65.952: [GC [PSYoungGen: 78837K->11256K(78848K)] 82897K->19543K(254976K), 0.0962789 secs]
73.377: [GC [PSYoungGen: 78840K->11260K(69248K)] 87127K->27342K(245376K), 0.0890153 secs]
77.938: [GC [PSYoungGen: 69244K->19542K(78144K)] 85326K->35624K(254272K), 0.0236485 secs]
83.007: [GC [PSYoungGen: 76822K->18333K(80960K)] 92904K->37861K(257088K), 0.1007859 secs]
91.264: [GC [PSYoungGen: 75229K->16045K(82432K)] 94757K->40041K(258560K), 0.0874944 secs]
97.515: [GC [PSYoungGen: 72941K->6440K(100288K)] 96937K->41397K(276416K), 0.1227819 secs]
106.366: [GC [PSYoungGen: 97512K->3956K(126144K)] 132469K->43596K(302272K), 0.0982573 secs]
114.011: [GC [PSYoungGen: 104692K->5246K(171584K)] 144332K->46515K(347712K), 0.0972135 secs]
121.696: [GC [PSYoungGen: 151422K->4595K(171200K)] 192691K->50596K(347328K), 0.0997297 secs]
131.357: [GC [PSYoungGen: 150771K->4244K(254464K)] 196772K->53941K(430592K), 0.1022893 secs]
288.364: [GC [PSYoungGen: 238164K->8666K(235968K)] 287861K->61652K(412096K), 0.0884445 secs]
297.527: [GC [PSYoungGen: 235930K->12210K(235520K)] 288916K->72886K(411648K), 0.0970622 secs]
300.876: [GC [PSYoungGen: 232775K->22514K(243712K)] 293451K->91712K(419840K), 0.0896641 secs]
302.277: [GC [PSYoungGen: 243698K->29180K(300160K)] 312896K->116730K(476288K), 0.1172576 secs]
304.287: [GC [PSYoungGen: 299769K->28943K(299968K)] 387320K->141716K(476096K), 0.1029239 secs]
306.433: [GC [PSYoungGen: 299919K->6831K(310080K)] 412692K->146559K(486208K), 0.1055606 secs]
308.730: [GC [PSYoungGen: 273775K->5377K(309120K)] 413503K->148026K(485248K), 0.0176229 secs]
311.867: [GC [PSYoungGen: 272321K->4171K(310080K)] 414970K->150445K(486208K), 0.0780572 secs]
316.559: [GC [PSYoungGen: 272907K->2352K(310912K)] 419181K->150306K(487040K), 0.0814960 secs]
321.431: [GC [PSYoungGen: 272816K->2224K(311808K)] 420770K->151770K(487936K), 0.0195984 secs]
326.477: [GC [PSYoungGen: 274352K->2376K(312576K)] 423898K->153514K(488704K), 0.0181888 secs]
331.359: [GC [PSYoungGen: 276232K->2224K(313536K)] 427370K->155030K(489664K), 0.0821171 secs]
336.450: [GC [PSYoungGen: 278192K->2256K(314688K)] 430998K->156642K(490816K), 0.0190569 secs]
>>>>
>>>>
336.469: [Full GC[Unloading class sun.reflect.GeneratedMethodAccessor773]
[Unloading class sun.reflect.GeneratedConstructorAccessor259]
[Unloading class sun.reflect.GeneratedConstructorAccessor154]
[Unloading class sun.reflect.GeneratedConstructorAccessor289]
[PSYoungGen: 2256K->0K(314688K)] [PSOldGen: 154386K->109726K(376832K)] 156642K->109726K(691520K) [PSPermGen: 54285K->54285K(110592K)], 2.5979181 secs]
>>>>
>>>>
342.507: [GC [PSYoungGen: 278400K->5954K(311872K)] 388126K->115680K(688704K), 0.0196707 secs]
345.645: [GC [PSYoungGen: 286978K->8429K(315328K)] 396704K->121705K(692160K), 0.0185399 secs]
349.908: [GC [PSYoungGen: 290925K->8000K(315328K)] 404201K->127828K(692160K), 0.0185565 secs]
354.791: [GC [PSYoungGen: 296960K->2320K(319744K)] 416788K->127720K(696576K), 0.0176147 secs]
360.372: [GC [PSYoungGen: 293648K->5125K(323840K)] 419048K->130525K(700672K), 0.0168338 secs]
365.858: [GC [PSYoungGen: 301445K->5856K(304576K)] 426845K->131256K(681408K), 0.0808504 secs]
371.278: [GC [PSYoungGen: 304544K->7888K(325184K)] 429944K->134885K(702016K), 0.0170485 secs]
376.939: [GC [PSYoungGen: 308560K->7152K(323648K)] 435557K->134148K(700480K), 0.0178370 secs]
382.394: [GC [PSYoungGen: 307824K->8848K(327552K)] 434820K->135844K(704384K), 0.0188606 secs]
388.103: [GC [PSYoungGen: 314896K->10416K(326656K)] 441892K->137412K(703488K), 0.0173568 secs]
393.822: [GC [PSYoungGen: 316464K->13413K(330368K)] 443460K->140409K(707200K), 0.0186272 secs]
399.556: [GC [PSYoungGen: 323429K->13744K(323776K)] 450425K->140740K(700608K), 0.0183015 secs]
405.175: [GC [PSYoungGen: 323760K->16693K(327360K)] 450756K->143689K(704192K), 0.0190493 secs]
410.909: [GC [PSYoungGen: 322229K->17024K(322560K)] 449225K->144020K(699392K), 0.0191946 secs]
416.457: [GC [PSYoungGen: 322560K->18713K(324352K)] 449556K->145710K(701184K), 0.0195976 secs]
422.053: [GC [PSYoungGen: 318361K->20256K(319936K)] 445358K->147252K(696768K), 0.0193531 secs]
427.636: [GC [PSYoungGen: 319904K->21872K(320128K)] 446900K->148868K(696960K), 0.0203252 secs]
433.068: [GC [PSYoungGen: 313840K->23456K(315456K)] 440836K->150452K(692288K), 0.0214092 secs]




as you can see the GC is running fine and freeing young gen frequently during the run, also it goes through one cycle of major run and freed the old gen.... however at the end of the run, the server still have 700MB as total memory and 480M as Free Memory (seen through the jboss web console and unix command prstat).... I wonder why is that... what I am expecting is that the server should run a major GC (maybe not immediately after my run, but some time after that) and return some of the free memory to the OS, sometimes I run into situation where my total memory equals 1.2G and the free = 1G !!!

Regards

[peterj]

and return some of the free memory to the OS

What makes you think this? Once the JVM requests memory from the OS for use in the heap, it never lets it go. Just because portions of the heap are empty does not mean the JVM will release that memory back to the OS. If you do not want the JVM to eat away at the OS memory, set the max heap size lower. As a guess, based on what I see from the gc data you posted, I would try 600MB as a max heap size and see how that does.

[gozilla]

Peter,

Actually, whether or not the jvm will return unused memory to the underlying OS is jvm/platform dependent.

For instance, with the Sun jvm, on Windows, it never occurs while it is supposed to happen on Solaris.

François

[peterj]

Yes, the Sun JVM does indeed behave differently(?) on Solaris than on Windows or Linux. I should have been more careful in my wording. ;-)

[gozilla]

IMHO, the Solaris behavior is the right one.

There are other differences wrt memory usage.
For instance on Solaris, if I understood correctly, you can run your jvm without placing limits on memory, letting the jvm size itself according to the load.

Sun tries probably to maintain some "advantages" of running java on Solaris. :-)

Francois