JBoss hangs for more then 15 seconds

[dmtitov]

Hi Everyone,

I faced very strange issue with JBoss AS 4.0.2 installed on Solaris 10. After startup JBoss works as expected but after a few days it starts to hang for more then 15 seconds. The frequency of such delays are growing each day. After JBoss restart it's works ok for a few days but then an issue start occuring again.

I have the following environment in my lab:

1) C++ application which sends HTTP requests to JBoss server.

2) Appications which are started on JBoss AS which process HTTP requests and generates XML page which is returned as a response.

     a) there are approximatelly 10 applications which are interconnected with eachother.

     b) applications are pretty complicated. They are using database calls, JBoss API, etc.

     c) I have a lot of http requests per sec.

3) CPU usage (~5%) and memory usage are fine.

I think that this is JBoss issue, not an issue of my applications because from the logs I can see that hangs occurs each time in different part of the source code (in JBoss source code and in application source code) and after that hang normal processing continues (no issue is printed from JBoss or app, it just hangs).

Here is some statistics collected from JBoss for a few applications:

App1 (the main one):

Start time: Tue Aug 30 17:59:45 PDT 2011 Startup time: 7 ms TLD scan time: 632 ms
Active sessions: 51 Session count: 107755 Max active sessions: 102 Rejected session creations: 0 Expired sessions: 109552 Longest session alive time: 2647 s Average session alive time: 0 s Processing time: 680 ms
JSPs loaded: 6 JSPs reloaded: 11

App2:

Start time: Tue Aug 30 17:59:53 PDT 2011 Startup time: 6 ms TLD scan time: 591 ms
Active sessions: 0 Session count: 3476 Max active sessions: 8 Rejected session creations: 0 Expired sessions: 3511 Longest session alive time: 2142 s Average session alive time: 9 s Processing time: 133 ms
JSPs loaded: 3 JSPs reloaded: 6

App3:

Start time: Tue Aug 30 17:59:10 PDT 2011 Startup time: 5 ms TLD scan time: 114 ms
Active sessions: 428 Session count: 108260 Max active sessions: 757 Rejected session creations: 0 Expired sessions: 215664 Longest session alive time: 1879 s Average session alive time: 1800 s Processing time: 5214 ms
JSPs loaded: 0 JSPs reloaded: 0

Guys, here are the people who has much more expirience in JBoss then me, so possibly someone faced such issue with JBoss or know some information that could be helpfull for me.

I think that probably it can be concerned with number of threads/pools on JBoss server, as far as I know there are configuration options which can be used to tune JBoss, could you please suggest how can I use them to fix an issue?

Note: currently I'm using the default JBoss configuration.

I'll be appreciated to get any information/opinion that could be helpfull for me!

Thanks in Advance,

Dmitry

[meme]

Hi Dmitry,

we're running JBoss 4.0.3SP1 on linux and we're not having this kind of issue (and it runs for months without a restart).

From this point I would say that there might be an memory leak, within your application or within the applicationserver.

To identify this you should monitor the memoryusage (heap and so on). You can use things like VisualVM or another profiler.

I would suggest that you'll use a profiler which can do long-term profiling (such as YourKit). Then you can see what's going

wrong.

marc

[dmtitov]

Hi Marc,

Thanks for your concern.

Unfortunatelly I don't have the long term memory usage information but what I see is that:

%CPU   PID  RSS %MEM     USER COMMAND
3.4 17697 1868152  5.7     root /usr/java/bin/java -server -Dprogram.name=S41jboss.start -Xms2048m -Xmx2048m -X

As I see the maximum Java heap size is set to 2G and the memory which is used by the java is close to this value, so theoretically this can lead to GC execution which can cause JBoss hang.

I'll try to get more details about it.

Thanks,

Dmitry

[meme]

I would suggest that you monitor your memory when it's near the 15seconds hang. I think you probably see some garbage collection at this point.

On the other hand, you should use an Profiler to see which classes are the ones using most of the heap. So you can probably find the issue.

[dmtitov]

Hi Everyone,

The root cause of the issue is that Full GC takes more than 10s, for this period of time JVM hangs:

43013.314: [GC [PSYoungGen: 602893K->15204K(636352K)] 1662241K->1106287K(2037184K), 0.1443227 secs] [Times: user=1.04 sys=0.26, real=0.14 secs]
43076.487: [GC [PSYoungGen: 589156K->50232K(624192K)] 1680239K->1154674K(2025024K), 0.1089039 secs] [Times: user=1.46 sys=0.09, real=0.11 secs]
43124.488: [GC [PSYoungGen: 624184K->53974K(626432K)] 1728626K->1207795K(2027264K), 0.2304841 secs] [Times: user=2.56 sys=0.35, real=0.23 secs]
43168.662: [GC [PSYoungGen: 613974K->46450K(606464K)] 1767795K->1251959K(2007296K), 0.2516265 secs] [Times: user=2.35 sys=0.42, real=0.25 secs]
43242.557: [GC [PSYoungGen: 606450K->27647K(631488K)] 1811959K->1279224K(2032320K), 0.2090754 secs] [Times: user=1.53 sys=0.37, real=0.21 secs]
43294.633: [GC [PSYoungGen: 406369K->15602K(630016K)] 1657946K->1293076K(2030848K), 0.1104384 secs] [Times: user=0.92 sys=0.18, real=0.11 secs]
43294.744: [Full GC (System) [PSYoungGen: 15602K->0K(630016K)] [PSOldGen: 1277473K->996371K(1400832K)] 1293076K->996371K(2030848K) [PSPermGen: 48809K->48809K(262144K)], 23.5863037 secs] [Times: user=23.60 sys=0.02, real=23.59 secs]
43375.848: [GC [PSYoungGen: 561088K->50042K(626688K)] 1557459K->1046414K(2027520K), 0.2346794 secs] [Times: user=1.16 sys=0.00, real=0.24 secs]
43446.587: [GC [PSYoungGen: 607354K->14938K(572288K)] 1603726K->1050588K(1973120K), 0.0667039 secs] [Times: user=1.09 sys=0.00, real=0.07 secs]
43527.545: [GC [PSYoungGen: 572250K->29911K(631744K)] 1607900K->1076241K(2032576K), 0.1639355 secs] [Times: user=2.50 sys=0.04, real=0.16 secs]

JBoss uses 1.7G of memory because this is how JVM configured on customer's server: -Xms2048m -Xmx2048m

Currently I'm thinking about the possibility of optimization of GC. I think that if I'll make YongGen less than it is then possibly Full GC will be executed more often and it will work faster, but I'm afraid that this would impact customer's system performance (at least I'm pretty sure that CPU usage will increase).

Probably somebody faced with such issue of have experience with GC optimization.

I'll be appreciated to hear any suggestions regarding GC optimization.

Thanks in Advance,

Dmitry

[peterj]

You might want to use the CMS garbage collector.

For suggestions on how to gather GC data and analyze it, see these white papers:

Java Garbage Collection Statistical Analysis 101

Java Garbage Collection Performance Analysis 201

at http://www.cmg.org/cgi-bin/search.cgi?q=java+peter+johnson&x=30&y=10