New timeout blocking call

[pants]

We're seeing behaviour where a server under certain unknown load conditions will block every request and eventually our server runs out of threads, memory etc.

Performing a thread dump shows that almost every pool thread is waiting on the newTimeout method in TimeoutFactory. See the thread dump snippet below...

"PoolThread-1171" prio=1 tid=0x084c4b38 nid=0x3263 waiting for monitor entry [bff92000..bff92cd8]
at org.jboss.util.timeout.TimeoutFactory.newTimeout(TimeoutFactory.java:418)
- waiting to lock <0x54960388> (a org.jboss.util.timeout.TimeoutFactory)
at org.jboss.util.timeout.TimeoutFactory.createTimeout(TimeoutFactory.java:558)
at org.jboss.tm.TransactionImpl.(TransactionImpl.java:219)
at org.jboss.tm.TxManager.begin(TxManager.java:117)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:247)
at org.jboss.ejb.plugins.TxInterceptorCMT.invokeHome(TxInterceptorCMT.java:98)
at org.jboss.ejb.plugins.SecurityInterceptor.invokeHome(SecurityInterceptor.java:92)
at org.jboss.ejb.plugins.LogInterceptor.invokeHome(LogInterceptor.java:120)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invokeHome(ProxyFactoryFinderInterceptor.java:93)
at org.jboss.ejb.StatelessSessionContainer.internalInvokeHome(StatelessSessionContainer.java:319)
at org.jboss.ejb.Container.invoke(Container.java:720)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invokeHome(BaseLocalProxyFactory.java:293)
at org.jboss.ejb.plugins.local.LocalHomeProxy.invoke(LocalHomeProxy.java:110)
at $Proxy38.create(Unknown Source)
at com.sportex.betex.middletier.facades.reference.ReferenceManager.createReferenceLocalObject(ReferenceManager.java:82)
at com.sportex.betex.middletier.facades.reference.ReferenceManager.webping(ReferenceManager.java:181)
at com.sportex.betex.webapplication.WebPingServlet.service(WebPingServlet.java:35)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at com.tangosol.coherence.servlet.SessionHelper.service(SessionHelper.java:1257)
at com.tangosol.coherence.servlet.api22.ServletWrapper.service(ServletWrapper.java:156)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:356)
at org.mortbay.jetty.servlet.WebApplicationHandler$Chain.doFilter(WebApplicationHandler.java:342)
at com.sportex.betex.webapplication.common.HeaderFilter.doFilter(HeaderFilter.java:59)
at com.tangosol.coherence.servlet.SessionHelper.filter(SessionHelper.java:930)
at com.tangosol.coherence.servlet.api23.FilterWrapper.doFilter(FilterWrapper.java:137)
at org.mortbay.jetty.servlet.WebApplicationHandler$Chain.doFilter(WebApplicationHandler.java:334)
at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:286)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:567)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1776)
at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:514)
at org.mortbay.http.HttpContext.handle(HttpContext.java:1726)
at org.mortbay.http.HttpServer.service(HttpServer.java:879)
at org.jboss.jetty.Jetty.service(Jetty.java:456)
at org.mortbay.http.HttpConnection.service(HttpConnection.java:790)
at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:952)
at org.mortbay.http.HttpConnection.handle(HttpConnection.java:807)
at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:196)
at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:289)
at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:487)

Looking at line 418 in TimeoutFactory shows...

418 --> if (++size == q.length) {
TimeoutImpl[] newQ = new TimeoutImpl[2*q.length];
System.arraycopy(q, 0, newQ, 0, q.length);
q = newQ;
}

I have no idea why every thread is blocking on this line.

Any ideas?

Can I provide any more information?

[adrian.brock]

Try to reproduce it with 3.2.5:

http://cvs.sourceforge.net/viewcvs.py/jboss/jboss-common/src/main/org/jboss/util/timeout/TimeoutFactory.java

[pants]

Thanks for the tip.

We're only able to reproduce this problem in production. Consequently, there has to be a reason to upgrade more substantial than just giving 3.2.5 a try.

We are currently running 3.2.3 (Jetty). Why would 3.2.5 fix it? Is there a specific change to the TimeoutFactory in the releases between 3.2.3 and 3.2.5?

Happy to try an upgrade, but would like to know why you think it might fix the problem.

[adrian.brock]

Because I made some fixes in this area.

Additionally, you'll find you won't get much help unless you can reproduce the problem
with the latest stable release. Nobody wants to waste time analyzing problems that
have already been fixed.

Off Topic, advice:
If you cannot reproduce a production problem in your staging environment,
your staging environment isn't very useful.

[pants]

We just saw the same problem occur this week, on the same server at the same time. We are running 44 nodes so its likely that the problem is environmental i.e O/S, hardware, etc.

Anyway, thanks for your time. Will upgrade soon nevertheless.

Re: your advice...you're preaching to the converted :)